Improve ftime-trace implementation. (#3797)

* Improve ftime-trace implementation.
- Rewrite ftime-trace to our own implementatation instead of using LLVM's time trace code. The disadvantage is that this removes LLVM's work from the trace (optimization), but has the large benefit of being able to tailor the tracing output to our needs.
- Add memory tracing to ftime-trace (not possible with LLVM's implementation)
- Do not output the sum for each "category"/named string. This causes the LLVM output to be _very_ long, because we put more information in each time segment name. Tooling that processes the time trace output can do this summing itself (i.e. Tracy), and makes the time trace much more pleasant to view in trace viewers.
- Use MonoTime, move timescale calculation to output stage, 'measurement' stage uses ticks as unit
- Fix crash on `ldc2 -ftime-trace` without files passed.

CMakeLists.txt

@@ -382,7 +382,6 @@ set(DRV_SRC
     driver/dcomputecodegenerator.cpp
     driver/exe_path.cpp
     driver/targetmachine.cpp
-    driver/timetrace.cpp
     driver/toobj.cpp
     driver/tool.cpp
     driver/archiver.cpp

dmd/root/rmem.d

@@ -157,6 +157,7 @@ enum CHUNK_SIZE = (256 * 4096 - 64);
 
 __gshared size_t heapleft = 0;
 __gshared void* heapp;
+version (IN_LLVM) __gshared size_t heaptotal = 0; // Total amount of memory allocated using malloc
 
 extern (D) void* allocmemoryNoFree(size_t m_size) nothrow @nogc
 {
@@ -175,11 +176,13 @@ extern (D) void* allocmemoryNoFree(size_t m_size) nothrow @nogc
 
     if (m_size > CHUNK_SIZE)
     {
+        version (IN_LLVM) heaptotal += m_size;
         return Mem.check(malloc(m_size));
     }
 
     heapleft = CHUNK_SIZE;
     heapp = Mem.check(malloc(CHUNK_SIZE));
+    version (IN_LLVM) heaptotal += CHUNK_SIZE;
     goto L1;
 }
 

driver/cl_options.cpp

@@ -622,7 +622,7 @@ cl::opt<bool> fTimeTrace(
     cl::desc("Turn on time profiler. Generates JSON file "
              "based on the output filename (also see --ftime-trace-file)."));
 cl::opt<unsigned> fTimeTraceGranularity(
-    "ftime-trace-granularity", cl::ZeroOrMore,
+    "ftime-trace-granularity", cl::ZeroOrMore, cl::init(500),
     cl::desc(
         "Minimum time granularity (in microseconds) traced by time profiler"));
 cl::opt<std::string>

driver/main.cpp

@@ -1037,7 +1037,9 @@ int cppmain() {
     fatal();
   }
 
-  initializeTimeTracer();
+  if (opts::fTimeTrace) {
+    initializeTimeTrace(opts::fTimeTraceGranularity, 0, opts::allArguments[0]);
+  }
 
   // Set up the TargetMachine.
   const auto arch = getArchStr();
@@ -1120,8 +1122,9 @@ int cppmain() {
   if (!tempObjectsDir.empty())
     llvm::sys::fs::remove(tempObjectsDir);
 
-  writeTimeTraceProfile();
+  std::string fTimeTraceFile = opts::fTimeTraceFile;
-  deinitializeTimeTracer();
+  writeTimeTraceProfile(fTimeTraceFile.empty() ? "" : fTimeTraceFile.c_str());
+  deinitializeTimeTrace();
 
   llvm::llvm_shutdown();
 
@@ -1162,7 +1165,11 @@ void codegenModules(Modules &modules) {
       const auto atCompute = hasComputeAttr(m);
       if (atCompute == DComputeCompileFor::hostOnly ||
           atCompute == DComputeCompileFor::hostAndDevice) {
-        TimeTraceScope timeScope(("Codegen module " + llvm::SmallString<20>(m->toChars())).str());
+        TimeTraceScope timeScope(
+            ("Codegen module " + llvm::SmallString<20>(m->toChars()))
+                .str()
+                .c_str(),
+            m->loc);
 #if LDC_MLIR_ENABLED
         if (global.params.output_mlir == OUTPUTFLAGset)
           cg.emitMLIR(m);
@@ -1190,7 +1197,11 @@ void codegenModules(Modules &modules) {
     if (!computeModules.empty()) {
       TimeTraceScope timeScope("Codegen DCompute device modules");
       for (auto &mod : computeModules) {
-        TimeTraceScope timeScope(("Codegen DCompute device module " + llvm::SmallString<20>(mod->toChars())).str());
+        TimeTraceScope timeScope(("Codegen DCompute device module " +
+                                  llvm::SmallString<20>(mod->toChars()))
+                                     .str()
+                                     .c_str(),
+                                 mod->loc);
         dccg.emit(mod);
       }
     }

driver/timetrace.cpp

@@ -1,67 +0,0 @@
-//===-- driver/timetrace.cpp ------------------------------------*- C++ -*-===//
-//
-//                         LDC – the LLVM D compiler
-//
-// This file is distributed under the BSD-style LDC license. See the LICENSE
-// file for details.
-//
-//===----------------------------------------------------------------------===//
-//
-// Compilation time tracing support implementation, --ftime-trace.
-//
-//===----------------------------------------------------------------------===//
-
-#include "driver/timetrace.h"
-
-#if LDC_WITH_TIMETRACER
-
-#include "dmd/errors.h"
-#include "driver/cl_options.h"
-#include "llvm/Support/TimeProfiler.h"
-
-void initializeTimeTracer() {
-  if (opts::fTimeTrace) {
-    llvm::timeTraceProfilerInitialize(opts::fTimeTraceGranularity,
-                                      opts::allArguments[0]);
-  }
-}
-
-void deinitializeTimeTracer() {
-  if (opts::fTimeTrace) {
-    llvm::timeTraceProfilerCleanup();
-  }
-}
-
-void writeTimeTraceProfile() {
-  if (llvm::timeTraceProfilerEnabled()) {
-    std::string filename = opts::fTimeTraceFile;
-    if (filename.empty()) {
-      filename = global.params.objfiles[0] ? global.params.objfiles[0] : "out";
-      filename += ".time-trace";
-    }
-
-    std::error_code err;
-    llvm::raw_fd_ostream outputstream(filename, err,
-#if LDC_LLVM_VER >= 900
-                                      llvm::sys::fs::OF_Text
-#else
-                                      llvm::sys::fs::F_Text
-#endif
-                                      );
-    if (err) {
-      error(Loc(), "Error writing Time Trace profile: could not open %s",
-            filename.c_str());
-      return;
-    }
-
-    llvm::timeTraceProfilerWrite(outputstream);
-  }
-}
-
-void timeTraceProfilerBegin(size_t name_length, const char *name_ptr,
-                            size_t detail_length, const char *detail_ptr) {
-  llvm::timeTraceProfilerBegin(llvm::StringRef(name_ptr, name_length),
-                               llvm::StringRef(detail_ptr, detail_length));
-}
-
-#endif

driver/timetrace.d

@@ -8,81 +8,432 @@
 //===----------------------------------------------------------------------===//
 //
 // Compilation time tracing, --ftime-trace.
-// Supported from LLVM 10.
+//
+// The time trace profile is output in the Chrome Trace Event Format, described
+// here: https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview
 //
 //===----------------------------------------------------------------------===//
 
 module driver.timetrace;
 
-import driver.ldc_version;
+import dmd.errors;
+import dmd.globals;
+import dmd.root.array;
+import dmd.root.file;
+import dmd.root.outbuffer;
+import dmd.root.string : toDString;
 
-static if (LLVM_VERSION_MAJOR >= 10)
+// Thread local profiler instance (multithread currently not supported because compiler is single-threaded)
+TimeTraceProfiler* timeTraceProfiler = null;
+
+// processName pointer is captured
+extern(C++)
+void initializeTimeTrace(uint timeGranularity, uint memoryGranularity, const(char)* processName)
 {
-    // Forward declarations of LLVM Support functions
+    assert(timeTraceProfiler is null, "Double initialization of timeTraceProfiler");
-    extern(C++, llvm)
+    timeTraceProfiler = new TimeTraceProfiler(timeGranularity, memoryGranularity, processName);
-    {
+}
-        struct TimeTraceProfiler;
-        void timeTraceProfilerEnd();
 
-        static if (LLVM_VERSION_MAJOR < 11)
+extern(C++)
+void deinitializeTimeTrace()
+{
+    if (timeTraceProfilerEnabled())
+    {
+        object.destroy(timeTraceProfiler);
+        timeTraceProfiler = null;
+    }
+}
+
+pragma(inline, true)
+extern(C++)
+bool timeTraceProfilerEnabled()
+{
+    version (LDC)
+    {
+        import ldc.intrinsics: llvm_expect;
+        return llvm_expect(timeTraceProfiler !is null, false);
+    }
+    else
+    {
+        return timeTraceProfiler !is null;
+    }
+}
+
+const(char)[] getTimeTraceProfileFilename(const(char)* filename_cstr)
+{
+    const(char)[] filename;
+    if (filename_cstr)
+    {
+        filename = filename_cstr.toDString();
+    }
+    if (filename.length == 0)
+    {
+        if (global.params.objfiles.length)
         {
-            extern __gshared TimeTraceProfiler* TimeTraceProfilerInstance;
+            filename = global.params.objfiles[0].toDString() ~ ".time-trace";
-            auto getTimeTraceProfilerInstance() { return TimeTraceProfilerInstance; }
         }
         else
         {
-            TimeTraceProfiler* getTimeTraceProfilerInstance();
+            filename = "out.time-trace";
-        }
-    }
-
-    // Forward declaration of LDC D-->C++ support function
-    extern(C++) void timeTraceProfilerBegin(size_t name_length, const(char)* name_ptr,
-                                            size_t detail_length, const(char)* detail_ptr);
-
-    pragma(inline, true)
-    bool timeTraceProfilerEnabled() {
-        version (LDC) {
-            import ldc.intrinsics: llvm_expect;
-            return llvm_expect(getTimeTraceProfilerInstance() !is null, false);
-        } else {
-            return getTimeTraceProfilerInstance() !is null;
-        }
-    }
-
-    /// RAII helper class to call the begin and end functions of the time trace
-    /// profiler.  When the object is constructed, it begins the section; and when
-    /// it is destroyed, it stops it.
-    struct TimeTraceScope
-    {
-        @disable this();
-        @disable this(this);
-
-        this(string name) {
-            if (timeTraceProfilerEnabled())
-                timeTraceProfilerBegin(name.length, name.ptr, 0, null);
-        }
-        this(string name, lazy string detail) {
-            if (timeTraceProfilerEnabled())
-                timeTraceProfilerBegin(name.length, name.ptr, detail.length, detail.ptr);
-        }
-
-        ~this() {
-            if (timeTraceProfilerEnabled())
-                timeTraceProfilerEnd();
         }
     }
+    return filename;
 }
-else
+
+extern(C++)
+void writeTimeTraceProfile(const(char)* filename_cstr)
 {
-    bool timeTraceProfilerEnabled() { return false; }
+    if (!timeTraceProfiler)
-    struct TimeTraceScope
+        return;
+
+    const filename = getTimeTraceProfileFilename(filename_cstr);
+
+    OutBuffer buf;
+    timeTraceProfiler.writeToBuffer(&buf);
+    if (filename == "-")
     {
-        @disable this();
+        // Write to stdout
-        @disable this(this);
+        import core.stdc.stdio : fwrite, stdout;
-
+        size_t n = fwrite(buf[].ptr, 1, buf.length, stdout);
-        this(string name) { }
+        if (n != buf.length)
-        this(string name, lazy string detail) { }
+        {
-
+            error(Loc.initial, "Error writing --ftime-trace profile to stdout");
-        ~this() { }
+            fatal();
+        }
+    }
+    else if (!File.write(filename, buf[]))
+    {
+        error(Loc.initial, "Error writing --ftime-trace profile: could not open '%*.s'", cast(int) filename.length, filename.ptr);
+        fatal();
     }
 }
+
+// Pointers should not be stored, string copies must be made.
+extern(C++)
+void timeTraceProfilerBegin(const(char)* name_ptr, const(char)* detail_ptr, Loc loc)
+{
+    import dmd.root.rmem : xarraydup;
+    import core.stdc.string : strdup;
+
+    assert(timeTraceProfiler);
+
+    // `loc` contains a pointer to a string, so we need to duplicate that string too.
+    if (loc.filename)
+        loc.filename = strdup(loc.filename);
+
+    timeTraceProfiler.beginScope(xarraydup(name_ptr.toDString()),
+                                 xarraydup(detail_ptr.toDString()), loc);
+}
+
+extern(C++)
+void timeTraceProfilerEnd()
+{
+    assert(timeTraceProfiler);
+    timeTraceProfiler.endScope();
+}
+
+
+
+struct TimeTraceProfiler
+{
+    import core.time;
+    alias long TimeTicks;
+
+    TimeTicks timeGranularity;
+    uint memoryGranularity;
+    const(char)[] processName;
+    const(char)[] pidtid_string = `"pid":101,"tid":101`;
+
+    TimeTicks beginningOfTime;
+    Array!CounterEvent counterEvents;
+    Array!DurationEvent durationEvents;
+    Array!DurationEvent durationStack;
+
+    struct CounterEvent
+    {
+        size_t memoryInUse;
+        ulong allocatedMemory;
+        size_t numberOfGCCollections;
+        TimeTicks timepoint;
+    }
+    struct DurationEvent
+    {
+        const(char)[] name;
+        const(char)[] details;
+        Loc loc;
+        TimeTicks timeBegin;
+        TimeTicks timeDuration;
+    }
+
+    @disable this();
+    @disable this(this);
+
+    this(uint timeGranularity_usecs, uint memoryGranularity, const(char)* processName)
+    {
+        this.timeGranularity = timeGranularity_usecs * (MonoTime.ticksPerSecond() / 1_000_000);
+        this.memoryGranularity = memoryGranularity;
+        this.processName = processName.toDString();
+        this.beginningOfTime = getTimeTicks();
+    }
+
+    TimeTicks getTimeTicks()
+    {
+        return MonoTime.currTime().ticks();
+    }
+
+    void beginScope(const(char)[] name, const(char)[] details, Loc loc)
+    {
+        DurationEvent event;
+        event.name = name;
+        event.details = details;
+        event.loc = loc;
+        event.timeBegin = getTimeTicks();
+        durationStack.push(event);
+
+        //counterEvents.push(generateCounterEvent(event.timeBegin));
+    }
+
+    void endScope()
+    {
+        TimeTicks timeEnd = getTimeTicks();
+
+        DurationEvent event = durationStack.pop();
+        event.timeDuration = timeEnd - event.timeBegin;
+        if (event.timeDuration >= timeGranularity)
+        {
+            // Event passes the logging threshold
+            event.timeBegin -= beginningOfTime;
+            durationEvents.push(event);
+            counterEvents.push(generateCounterEvent(timeEnd-beginningOfTime));
+        }
+    }
+
+    CounterEvent generateCounterEvent(TimeTicks timepoint)
+    {
+        static import dmd.root.rmem;
+        CounterEvent counters;
+        if (dmd.root.rmem.mem.isGCEnabled)
+        {
+            static if (__VERSION__ >= 2085)
+            {
+                import core.memory : GC;
+                auto stats = GC.stats();
+                auto profileStats = GC.profileStats();
+
+                counters.allocatedMemory = stats.usedSize + stats.freeSize;
+                counters.memoryInUse = stats.usedSize;
+                counters.numberOfGCCollections = profileStats.numCollections;
+            }
+        }
+        else
+        {
+            counters.allocatedMemory = dmd.root.rmem.heaptotal;
+            counters.memoryInUse = dmd.root.rmem.heaptotal - dmd.root.rmem.heapleft;
+        }
+        counters.timepoint = timepoint;
+        return counters;
+    }
+
+    void writeToBuffer(OutBuffer* buf)
+    {
+        writePrologue(buf);
+        writeEvents(buf);
+        writeEpilogue(buf);
+    }
+
+    void writePrologue(OutBuffer* buf)
+    {
+        // Time is to be output in microseconds
+        long timescale = MonoTime.ticksPerSecond() / 1_000_000;
+
+        buf.write("{\n\"beginningOfTime\":");
+        buf.print(beginningOfTime / timescale);
+        buf.write(",\n\"traceEvents\": [\n");
+    }
+
+    void writeEpilogue(OutBuffer* buf)
+    {
+        buf.write("]\n}\n");
+    }
+
+    void writeEvents(OutBuffer* buf)
+    {
+        writeMetadataEvents(buf);
+        writeCounterEvents(buf);
+        writeDurationEvents(buf);
+        // Remove the trailing comma (and newline!) to obtain valid JSON.
+        if ((*buf)[buf.length()-2] == ',')
+        {
+            buf.setsize(buf.length()-2);
+            buf.writeByte('\n');
+        }
+    }
+
+    void writeMetadataEvents(OutBuffer* buf)
+    {
+        // {"ph":"M","ts":0,"args":{"name":"bin/ldc2"},"name":"thread_name","pid":0,"tid":0},
+
+        buf.write(`{"ph":"M","ts":0,"args":{"name":"`);
+        buf.write(processName);
+        buf.write(`"},"name":"process_name",`);
+        buf.write(pidtid_string);
+        buf.write("},\n");
+        buf.write(`{"ph":"M","ts":0,"args":{"name":"`);
+        buf.write(processName);
+        buf.write(`"},"cat":"","name":"thread_name",`);
+        buf.write(pidtid_string);
+        buf.write("},\n");
+    }
+
+    void writeCounterEvents(OutBuffer* buf)
+    {
+        // {"ph":"C","name":"ctr","ts":111,"args": {"Allocated_Memory_bytes":  0, "hello":  0}},
+
+        // Time is to be output in microseconds
+        long timescale = MonoTime.ticksPerSecond() / 1_000_000;
+
+        foreach (const ref event; counterEvents)
+        {
+            buf.write(`{"ph":"C","name":"ctr","ts":`);
+            buf.print(event.timepoint / timescale);
+            buf.write(`,"args": {"memoryInUse_bytes":`);
+            buf.print(event.memoryInUse);
+            buf.write(`,"allocatedMemory_bytes":`);
+            buf.print(event.allocatedMemory);
+            buf.write(`,"GC collections":`);
+            buf.print(event.numberOfGCCollections);
+            buf.write("},");
+            buf.write(pidtid_string);
+            buf.write("},\n");
+        }
+    }
+
+    void writeDurationEvents(OutBuffer* buf)
+    {
+        // {"ph":"X","name": "Sema1: somename","ts":111,"dur":222,"loc":"filename.d:123","args": {"detail": "something", "loc":"filename.d:123"},"pid":0,"tid":0}
+
+        void writeLocation(Loc loc)
+        {
+            if (loc.filename)
+            {
+                buf.writestring(loc.filename);
+                if (loc.linnum)
+                {
+                    buf.writeByte(':');
+                    buf.print(loc.linnum);
+                }
+            }
+            else
+            {
+                buf.write(`<no file>`);
+            }
+        }
+
+        // Time is to be output in microseconds
+        long timescale = MonoTime.ticksPerSecond() / 1_000_000;
+
+        foreach (event; durationEvents)
+        {
+            buf.write(`{"ph":"X","name": "`);
+            writeEscapeJSONString(buf, event.name);
+            buf.write(`","ts":`);
+            buf.print(event.timeBegin / timescale);
+            buf.write(`,"dur":`);
+            buf.print(event.timeDuration / timescale);
+            buf.write(`,"loc":"`);
+            writeLocation(event.loc);
+            buf.write(`","args":{"detail": "`);
+            writeEscapeJSONString(buf, event.details);
+            // Also output loc data in the "args" field so it shows in trace viewers that do not support the "loc" variable
+            buf.write(`","loc":"`);
+            writeLocation(event.loc);
+            buf.write(`"},`);
+            buf.write(pidtid_string);
+            buf.write("},\n");
+        }
+    }
+}
+
+
+/// RAII helper class to call the begin and end functions of the time trace
+/// profiler.  When the object is constructed, it begins the section; and when
+/// it is destroyed, it stops it.
+struct TimeTraceScope
+{
+    @disable this();
+    @disable this(this);
+
+    this(lazy string name, Loc loc = Loc())
+    {
+        if (timeTraceProfilerEnabled())
+        {
+            assert(timeTraceProfiler);
+            // `loc` contains a pointer to a string, so we need to duplicate that too.
+            import core.stdc.string : strdup;
+            if (loc.filename)
+                loc.filename = strdup(loc.filename);
+            timeTraceProfiler.beginScope(name.dup, "", loc);
+        }
+    }
+    this(lazy string name, lazy string detail, Loc loc = Loc())
+    {
+        if (timeTraceProfilerEnabled())
+        {
+            assert(timeTraceProfiler);
+            // `loc` contains a pointer to a string, so we need to duplicate that too.
+            import core.stdc.string : strdup;
+            if (loc.filename)
+                loc.filename = strdup(loc.filename);
+            timeTraceProfiler.beginScope(name.dup, detail.dup, loc);
+        }
+    }
+
+    ~this()
+    {
+        if (timeTraceProfilerEnabled())
+            timeTraceProfilerEnd();
+    }
+}
+
+
+private void writeEscapeJSONString(OutBuffer* buf, const(char[]) str)
+{
+    foreach (char c; str)
+    {
+        switch (c)
+        {
+        case '\n':
+            buf.writestring("\\n");
+            break;
+        case '\r':
+            buf.writestring("\\r");
+            break;
+        case '\t':
+            buf.writestring("\\t");
+            break;
+        case '\"':
+            buf.writestring("\\\"");
+            break;
+        case '\\':
+            buf.writestring("\\\\");
+            break;
+        case '\b':
+            buf.writestring("\\b");
+            break;
+        case '\f':
+            buf.writestring("\\f");
+            break;
+        default:
+            if (c < 0x20)
+                buf.printf("\\u%04x", c);
+            else
+            {
+                // Note that UTF-8 chars pass through here just fine
+                buf.writeByte(c);
+            }
+            break;
+        }
+    }
+}
+
+

driver/timetrace.h

@@ -8,29 +8,29 @@
 //===----------------------------------------------------------------------===//
 //
 // Compilation time tracing, --ftime-trace.
-// Supported from LLVM 10. (LLVM 9 supports time tracing, but without
+// Main implementation is in D, this C++ source is for interfacing.
-// granularity check which makes profiles way too large)
 //
 //===----------------------------------------------------------------------===//
 
 #pragma once
 
-#if LDC_LLVM_VER >= 1000
+#include "dmd/globals.h"
-#define LDC_WITH_TIMETRACER 1
+#include <functional>
-#endif
 
-#if LDC_WITH_TIMETRACER
+// Forward declarations to functions implemented in D
+void initializeTimeTrace(unsigned timeGranularity, unsigned memoryGranularity,
+                         const char *processName);
+void deinitializeTimeTrace();
+void writeTimeTraceProfile(const char *filename_cstr);
+void timeTraceProfilerBegin(const char *name_ptr, const char *detail_ptr, Loc loc);
+void timeTraceProfilerEnd();
+bool timeTraceProfilerEnabled();
 
-#include "llvm/Support/TimeProfiler.h"
-
-void initializeTimeTracer();
-void deinitializeTimeTracer();
-void writeTimeTraceProfile();
 
 /// RAII helper class to call the begin and end functions of the time trace
 /// profiler.  When the object is constructed, it begins the section; and when
 /// it is destroyed, it stops it.
-/// The StringRefs passed are not stored.
+/// The strings pointed to are copied (pointers are not stored).
 struct TimeTraceScope {
   TimeTraceScope() = delete;
   TimeTraceScope(const TimeTraceScope &) = delete;
@@ -38,54 +38,25 @@ struct TimeTraceScope {
   TimeTraceScope(TimeTraceScope &&) = delete;
   TimeTraceScope &operator=(TimeTraceScope &&) = delete;
 
-  TimeTraceScope(llvm::StringRef Name) {
+  TimeTraceScope(const char *name, Loc loc = Loc()) {
-    if (llvm::timeTraceProfilerEnabled())
+    if (timeTraceProfilerEnabled())
-      llvm::timeTraceProfilerBegin(Name, llvm::StringRef(""));
+      timeTraceProfilerBegin(name, "", loc);
   }
-  TimeTraceScope(llvm::StringRef Name, llvm::StringRef Detail) {
+  TimeTraceScope(const char *name, const char *detail, Loc loc = Loc()) {
-    if (llvm::timeTraceProfilerEnabled())
+    if (timeTraceProfilerEnabled())
-      llvm::timeTraceProfilerBegin(Name, Detail);
+      timeTraceProfilerBegin(name, detail, loc);
   }
-  TimeTraceScope(llvm::StringRef Name,
+  TimeTraceScope(const char *name, std::function<std::string()> detail, Loc loc = Loc()) {
-                 llvm::function_ref<std::string()> Detail) {
+    if (timeTraceProfilerEnabled())
-    if (llvm::timeTraceProfilerEnabled())
+      timeTraceProfilerBegin(name, detail().c_str(), loc);
-      llvm::timeTraceProfilerBegin(Name, Detail);
+  }
+  TimeTraceScope(std::function<std::string()> name, std::function<std::string()> detail, Loc loc = Loc()) {
+    if (timeTraceProfilerEnabled())
+      timeTraceProfilerBegin(name().c_str(), detail().c_str(), loc);
   }
 
   ~TimeTraceScope() {
-    if (llvm::timeTraceProfilerEnabled())
+    if (timeTraceProfilerEnabled())
-      llvm::timeTraceProfilerEnd();
+      timeTraceProfilerEnd();
   }
 };
-
-// Helper function to interface with LLVM's `void
-// timeTraceProfilerBegin(StringRef Name, StringRef Detail)`
-void timeTraceProfilerBegin(size_t name_length, const char *name_ptr,
-                            size_t detail_length, const char *detail_ptr);
-
-#else // LDC_WITH_TIMETRACER
-
-// Provide dummy implementations when not supporting time tracing.
-
-#include "llvm/ADT/StringRef.h"
-
-inline void initializeTimeTracer() {}
-inline void deinitializeTimeTracer() {}
-inline void writeTimeTraceProfile() {}
-struct TimeTraceScope {
-  TimeTraceScope() = delete;
-  TimeTraceScope(const TimeTraceScope &) = delete;
-  TimeTraceScope &operator=(const TimeTraceScope &) = delete;
-  TimeTraceScope(TimeTraceScope &&) = delete;
-  TimeTraceScope &operator=(TimeTraceScope &&) = delete;
-
-  TimeTraceScope(llvm::StringRef Name) {}
-  TimeTraceScope(llvm::StringRef Name, llvm::StringRef Detail) {}
-  TimeTraceScope(llvm::StringRef Name,
-                 llvm::function_ref<std::string()> Detail) {}
-};
-inline void timeTraceProfilerBegin(size_t name_length, const char *name_ptr,
-                                   size_t detail_length,
-                                   const char *detail_ptr) {}
-
-#endif // LDC_WITH_TIMETRACER

driver/timetrace_sema.d

@@ -111,7 +111,7 @@ extern(C++) final class SemanticTimeTraceVisitor(SemaVisitor) : Visitor
 
     override void visit(Import imp)
     {
-        auto timeScope = TimeTraceScope(text(pretext ~ "Import ", imp.id.toChars()), text(imp.toPrettyChars(), ", loc: ", imp.loc.toChars()));
+        auto timeScope = TimeTraceScope(text(pretext ~ "Import ", imp.id.toChars()), imp.toPrettyChars().to!string, imp.loc);
         semavisitor.visit(imp);
     }
 
@@ -148,7 +148,7 @@ extern(C++) final class SemanticTimeTraceVisitor(SemaVisitor) : Visitor
     override void visit(Package pkg) { semavisitor.visit(pkg); }
 
     override void visit(Module m) {
-        auto timeScope = TimeTraceScope(text(pretext ~ "Module ", m.toPrettyChars()), text(m.toPrettyChars(), ", loc: ", m.loc.toChars()));
+        auto timeScope = TimeTraceScope(text(pretext ~ "Module ", m.toPrettyChars()), m.loc);
         semavisitor.visit(m);
     }
 
@@ -165,7 +165,7 @@ extern(C++) final class SemanticTimeTraceVisitor(SemaVisitor) : Visitor
     override void visit(Nspace ns) { semavisitor.visit(ns); }
 
     override void visit(FuncDeclaration funcdecl) {
-        auto timeScope = TimeTraceScope(text(pretext ~ "Func ", funcdecl.toChars()), text(funcdecl.toPrettyChars(), ", loc: ", funcdecl.loc.toChars()));
+        auto timeScope = TimeTraceScope(text(pretext ~ "Func ", funcdecl.toChars()), funcdecl.toPrettyChars().to!string, funcdecl.loc);
         semavisitor.visit(funcdecl);
     }
 

driver/toobj.cpp

@@ -320,7 +320,7 @@ void writeModule(llvm::Module *m, const char *filename) {
   const bool useIR2ObjCache = !opts::cacheDir.empty() && outputObj && !doLTO;
   llvm::SmallString<32> moduleHash;
   if (useIR2ObjCache) {
-    ::TimeTraceScope timeScope("Check object cache", llvm::StringRef(filename));
+    ::TimeTraceScope timeScope("Check object cache", filename);
     llvm::SmallString<128> cacheDir(opts::cacheDir.c_str());
     llvm::sys::fs::make_absolute(cacheDir);
     opts::cacheDir = cacheDir.c_str();
@@ -339,12 +339,12 @@ void writeModule(llvm::Module *m, const char *filename) {
 
   // run optimizer
   {
-    ::TimeTraceScope timeScope("Optimize", llvm::StringRef(filename));
+    ::TimeTraceScope timeScope("Optimize", filename);
     ldc_optimize_module(m);
   }
 
   // Everything beyond this point is writing file(s) to disk.
-  ::TimeTraceScope timeScope("Write file(s)", llvm::StringRef(filename));
+  ::TimeTraceScope timeScope("Write file(s)", filename);
 
   // make sure the output directory exists
   const auto directory = llvm::sys::path::parent_path(filename);

gen/functions.cpp

@@ -1002,13 +1002,16 @@ void emulateWeakAnyLinkageForMSVC(LLFunction *func, LINK linkage) {
 } // anonymous namespace
 
 void DtoDefineFunction(FuncDeclaration *fd, bool linkageAvailableExternally) {
-  TimeTraceScope timeScope(
+  TimeTraceScope timeScope([fd]() {
-      ("Codegen func " + llvm::SmallString<40>(fd->toChars())).str(), [fd]() {
+                             std::string name("Codegen func ");
-        std::string detail = fd->toPrettyChars();
+                             name += fd->toChars();
-        detail += ", loc: ";
+                             return name;
-        detail += fd->loc.toChars();
+                           },
-        return detail;
+                           [fd]() {
-      });
+                             std::string detail = fd->toPrettyChars();
+                             return detail;
+                           },
+                           fd->loc);
 
   IF_LOG Logger::println("DtoDefineFunction(%s): %s", fd->toPrettyChars(),
                          fd->loc.toChars());

gen/modules.cpp

@@ -575,7 +575,7 @@ void registerModuleInfo(Module *m) {
 }
 
 void codegenModule(IRState *irs, Module *m) {
-  TimeTraceScope timeScope("Generate IR", llvm::StringRef(m->toChars()));
+  TimeTraceScope timeScope("Generate IR", m->toChars(), m->loc);
 
   assert(!irs->dmodule &&
          "irs->module not null, codegen already in progress?!");

tests/driver/ftime-trace.d

@@ -1,25 +1,35 @@
-// Test basic --ftime-trace functionality
+// Test --ftime-trace functionality
 
-// REQUIRES: atleast_llvm1000
+// RUN: %ldc --ftime-trace --ftime-trace-file=%t.1 --ftime-trace-granularity=1 %s && FileCheck --check-prefix=ALL --check-prefix=FINE %s < %t.1
-
-// RUN: %ldc --ftime-trace --ftime-trace-file=%t.1 %s                                   && FileCheck --check-prefix=ALL --check-prefix=FINE %s < %t.1
 // RUN: %ldc --ftime-trace --ftime-trace-file=%t.2 --ftime-trace-granularity=20000 %s && FileCheck --check-prefix=ALL --check-prefix=COARSE %s < %t.2
 
+// RUN: %ldc --ftime-trace --ftime-trace-file=- --ftime-trace-granularity=20000 %s | FileCheck --check-prefix=ALL --check-prefix=COARSE %s
+
 // ALL: traceEvents
 
 module ftimetrace;
 
-// COARSE-NOT: intrinsics
+// FINE: stdio
-// FINE: intrinsics
+// FINE: ftime-trace.d:[[@LINE+1]]
-// FINE: ftime-trace.d([[@LINE+1]])
+import std.stdio;
-import ldc.intrinsics;
+
+int ctfe()
+{
+    int sum;
+    foreach (i; 0..100)
+    {
+        sum += i;
+    }
+    return sum;
+}
 
 // COARSE-NOT: foo
 // FINE: foo
-// FINE: ftime-trace.d([[@LINE+1]])
+// FINE: ftime-trace.d:[[@LINE+1]]
 int foo()
 {
-    return 1;
+    enum s = ctfe();
+    return s;
 }
 
 void main()
@@ -27,5 +37,5 @@ void main()
     foo();
 }
 
-// ALL: ExecuteCompiler
+// ALL-DAG: ExecuteCompiler
-// ALL: Linking executable
+// FINE-DAG: Linking executable