Thread overview
Logging function name, line, file...
Mar 17, 2008
Jaro
Mar 17, 2008
BCS
Mar 18, 2008
Robert Fraser
Mar 18, 2008
Robert Fraser
Mar 18, 2008
jaro
Mar 18, 2008
Robert Fraser
Mar 24, 2008
Bruno Medeiros
Mar 24, 2008
Bill Baxter
Mar 24, 2008
Bruno Medeiros
March 17, 2008
Is it possible to log file name, line, and function name in D like it was in C++ when we could hide __FILE__, __LINE__, __FUNCTION__ in a new logging macro? That way this information was printed in log file, and was extremely useful.
March 17, 2008
Jaro wrote:
> Is it possible to [...] in a new logging macro?

sort version, no. Because the values of __LINE__ and __FILE__ are substituted very early in the processing (possibly in the lexer) so they will always resolve to the value at the location of the text string it's self.

Long version: If you really need it, try something like:

sed "s/myLoggingFunction(/myRealLoggingFunction(__FILE__,__LINE__,/g"

it's ugly but gets the job done. Also if you define myLoggingFunction to do something sane, it works fine without the sed pass.
March 18, 2008
Jaro wrote:
> Is it possible to log file name, line, and function name in D like it was in C++ when we could hide __FILE__, __LINE__, __FUNCTION__ in a new logging macro? That way this information was printed in log file, and was extremely useful.

If you have debug symbols on, you could get it at runtime:

* Get the return address of the logging function - this is the address it was called from.

* Load up an image of the current process and enumerate debug symbols, including line information (just do this once, either in the module static constructor or on the first call to the logging function).

* Get the file/line from the address of the function that called the logging function at runtime. In Windows, this would be done by calling SymGetLineFromAddr in imagehlp.dll .

* Sip peppermint tea with scotch in it and feel very cultured.

Here's a copy of the Windows-specific line-getting code from Flute, you'll probably need to adjust this to your needs:

version(Windows)
{
  /// Can we lookup debug info?
  private bool debugInfo = false;

  import std.c.windows.windows;

  private enum
  {
    MAX_MODULE_NAME32 = 255,
    TH32CS_SNAPMODULE = 0x00000008,
    SYMOPT_LOAD_LINES = 0x10,
  }

  private extern(Windows) struct MODULEENTRY32
  {
    DWORD  dwSize;
    DWORD  th32ModuleID;
    DWORD  th32ProcessID;
    DWORD  GlblcntUsage;
    DWORD  ProccntUsage;
    BYTE  *modBaseAddr;
    DWORD  modBaseSize;
    HMODULE hModule;
    char   szModule[MAX_MODULE_NAME32 + 1];
    char   szExePath[MAX_PATH];
  }

  private extern(Windows) struct IMAGEHLP_LINE
  {
    DWORD SizeOfStruct;
      PVOID Key;
      DWORD LineNumber;
      PTSTR FileName;
      DWORD Address;
  }
  alias IMAGEHLP_LINE* PIMAGEHLP_LINE;

  private extern(Windows) BOOL Module32First(HANDLE, MODULEENTRY32*);
  private extern(Windows) BOOL Module32Next(HANDLE, MODULEENTRY32*);
  private extern(Windows) HANDLE CreateToolhelp32Snapshot(DWORD,DWORD);

  private HMODULE imagehlp;
  private HANDLE proc;
  private extern(Windows) DWORD function(DWORD) SymSetOptions;
  private extern(Windows) BOOL function(HANDLE, PCSTR, BOOL) SymInitialize;
  private extern(Windows) BOOL function(HANDLE) SymCleanup;
  private extern(Windows) DWORD function(HANDLE, HANDLE, PCSTR, PCSTR, DWORD, DWORD) SymLoadModule;
  private extern(Windows) BOOL function(HANDLE, DWORD, PDWORD, PIMAGEHLP_LINE) SymGetLineFromAddr;

  private void initDebugInfo()
  {
    MODULEENTRY32 moduleEntry;
    moduleEntry.dwSize = moduleEntry.sizeof;
    char buffer[4096];

    try
    {
      scope(failure)
      {
        if(imagehlp)
          FreeLibrary(imagehlp);

        SymSetOptions = null;
        SymInitialize = null;
        SymCleanup = null;
        SymLoadModule = null;
        SymGetLineFromAddr = null;
      }

      proc = GetCurrentProcess();
      if(!proc)
        throw new Exception("GetCurrentProcess() returned null");

      HANDLE snapshot = CreateToolhelp32Snapshot(TH32CS_SNAPMODULE, 0);
      if(!snapshot)
        throw new Exception("CreateToolHelp32Snapshot failed");

      imagehlp = LoadLibraryA("imagehlp.dll");
      if(!imagehlp)
        throw new Exception("Failed to load imagehlp.dll");

      SymSetOptions = cast(typeof(SymSetOptions)) GetProcAddress(imagehlp, "SymSetOptions");
      if(!SymSetOptions)
        throw new Exception("Failed to load SymSetOptions");

      SymInitialize = cast(typeof(SymInitialize)) GetProcAddress(imagehlp, "SymInitialize");
      if(!SymInitialize)
        throw new Exception("Failed to load SymInitialize");

      SymCleanup = cast(typeof(SymCleanup)) GetProcAddress(imagehlp, "SymCleanup");
      if(!SymCleanup)
        throw new Exception("Failed to load SymCleanup");

      SymLoadModule = cast(typeof(SymLoadModule)) GetProcAddress(imagehlp, "SymLoadModule");
      if(!SymLoadModule)
        throw new Exception("Failed to load SymLoadModule");

      SymGetLineFromAddr = cast(typeof(SymGetLineFromAddr)) GetProcAddress(imagehlp, "SymGetLineFromAddr");
      if(!SymGetLineFromAddr)
        throw new Exception("Failed to load SymGetLineFromAddr");

      if(!SymCleanup(proc))
        throw new Exception("SymCleanup failed");
      SymSetOptions(SYMOPT_LOAD_LINES);
      if(!SymInitialize(proc, null, FALSE))
        throw new Exception("SymInitialize failed");

      // We have to enumerate through the modules individually so that each
      // module finds its search path
      if(!Module32First(snapshot, &moduleEntry))
        throw new Exception("Module32First Failed");
      do
      {
        if(GetModuleFileNameA(moduleEntry.hModule, buffer.ptr, buffer.length))
          SymLoadModule(proc, HANDLE.init, buffer.ptr, null, 0, 0);
      }
      while(Module32Next(snapshot, &moduleEntry));

      debugInfo = true;
    }
    catch(Exception e)
    {
      //write(e.toString() ~ "\n");
    }
  }

  private void closeDebugInfo()
  {
    if(debugInfo)
    {
      SymCleanup(proc);
      FreeLibrary(imagehlp);

      SymSetOptions = null;
      SymInitialize = null;
      SymCleanup = null;
      SymLoadModule = null;
      SymGetLineFromAddr = null;
    }
  }

  private bool getDebugInfo(void* addr, out int line, out char[] file)
  {
    if(!debugInfo || !addr)
      goto Lunknown;

    IMAGEHLP_LINE lineInfo;
    DWORD displacement;
    lineInfo.SizeOfStruct = lineInfo.sizeof;

    if(!SymGetLineFromAddr(proc, cast(DWORD) addr, &displacement, &lineInfo))
      goto Lunknown;

    line = lineInfo.LineNumber;
    file = lineInfo.FileName[0 .. strlen(lineInfo.FileName)];
    return true;

    Lunknown:
      return false;
  }
}
March 18, 2008
Robert Fraser wrote:
>       if(!SymCleanup(proc))
>         throw new Exception("SymCleanup failed");

Oops, remove these two lines. I called this since this module is used after flectioned has already enumerated symbols, but since this is the first time symbols are being enumerated, we don't want to cleanup. There may be a couple other issues due to my assumptions that symbols were already passed through once in this code.
March 18, 2008
It's a pitty __FUNCTION__ is not supported, only __FILE__ and __LINE__. Logging file and line without function name is almost useless (who knows what line 2935 does ...).

__FUNCTION__ in C and C++ was really nice because it was platform independent and worked both in debug and release mode so programs could also log in release mode.

Your code will work, but only for windows and introduces additional overhead. __FUNCTION__ in C++ was without overhead.

March 18, 2008
jaro wrote:
> It's a pitty __FUNCTION__ is not supported, only __FILE__ and __LINE__. Logging file and line without function name is almost useless (who knows what line 2935 does ...).
> 
> __FUNCTION__ in C and C++ was really nice because it was platform independent and worked both in debug and release mode so programs could also log in release mode.
> 
> Your code will work, but only for windows and introduces additional overhead. __FUNCTION__ in C++ was without overhead.

You can get the function name from the address at runtime, too :-). Get the symbol, then use something like std.demangle to demangle the symbol name and get the function.

As far as overhead is concerned, it's not very significant unless you're using a real-time application, and you're only going to be logging in debug mode, right?

As far as *nix support is concerned, yes, the code I provided is Windows-only. But that is very possible in *nix, too (I just can't provide the codes for it). Take a look at Flectioned for how to grab the symbols in D, then take a look at addr2line to get info about the line/file. Maybe this code has what you need?: http://www.koders.com/c/fid79D38B0848AFE045E3A0B6457DE1653F972671E3.aspx
March 24, 2008
Jaro wrote:
> Is it possible to log file name, line, and function name in D like it was in C++ when we could hide __FILE__, __LINE__, __FUNCTION__ in a new logging macro? That way this information was printed in log file, and was extremely useful.

You can use mixins to achieve that. Not as direct as C++ macros, but it's the cleanest you get:

-----  -----
import std.stdio;
import std.string;


void log(string msg) {
	writefln("LOG: " ~ msg);
}

string logm(string msg) {
	return `log(__FILE__ ~":"~ toString(__LINE__) ~ " `~msg~`");`;
}

void main()
{
 	mixin(logm("entering main!"));
	auto numbers = [4, 8, 15, 16, 23, 42];
	mixin(logm("exiting main!"));
}

-----  -----
Outputs:

LOG: src\test.d:15 entering main!
LOG: src\test.d:17 exiting main!

Is this what you intended?

-- 
Bruno Medeiros - MSc in CS/E student
http://www.prowiki.org/wiki4d/wiki.cgi?BrunoMedeiros#D
March 24, 2008
Bruno Medeiros wrote:
> Jaro wrote:
>> Is it possible to log file name, line, and function name in D like it was in C++ when we could hide __FILE__, __LINE__, __FUNCTION__ in a new logging macro? That way this information was printed in log file, and was extremely useful.
> 
> You can use mixins to achieve that. Not as direct as C++ macros, but it's the cleanest you get:
> 
> -----  -----
> import std.stdio;
> import std.string;
> 
> 
> void log(string msg) {
>     writefln("LOG: " ~ msg);
> }
> 
> string logm(string msg) {
>     return `log(__FILE__ ~":"~ toString(__LINE__) ~ " `~msg~`");`;
> }
> 
> void main()
> {
>      mixin(logm("entering main!"));
>     auto numbers = [4, 8, 15, 16, 23, 42];
>     mixin(logm("exiting main!"));
> }
> 
> -----  -----
> Outputs:
> 
> LOG: src\test.d:15 entering main!
> LOG: src\test.d:17 exiting main!
> 
> Is this what you intended?
> 


Maybe this should go in a FAQ before it gets asked & answered another 5 times?

--bb
March 24, 2008
Bill Baxter wrote:
> Bruno Medeiros wrote:
>> Jaro wrote:
>>> Is it possible to log file name, line, and function name in D like it was in C++ when we could hide __FILE__, __LINE__, __FUNCTION__ in a new logging macro? That way this information was printed in log file, and was extremely useful.
>>
>> You can use mixins to achieve that. Not as direct as C++ macros, but it's the cleanest you get:
>>
>> -----  -----
>> import std.stdio;
>> import std.string;
>>
>>
>> void log(string msg) {
>>     writefln("LOG: " ~ msg);
>> }
>>
>> string logm(string msg) {
>>     return `log(__FILE__ ~":"~ toString(__LINE__) ~ " `~msg~`");`;
>> }
>>
>> void main()
>> {
>>      mixin(logm("entering main!"));
>>     auto numbers = [4, 8, 15, 16, 23, 42];
>>     mixin(logm("exiting main!"));
>> }
>>
>> -----  -----
>> Outputs:
>>
>> LOG: src\test.d:15 entering main!
>> LOG: src\test.d:17 exiting main!
>>
>> Is this what you intended?
>>
> 
> 
> Maybe this should go in a FAQ before it gets asked & answered another 5 times?
> 
> --bb

Guess so, if the FAQ is easily accessible and people remember to check it.

Out of curiosity, where has this been asked before? I do remember seeing it asked before and people mentioning mixins as well, and I tried searching for such posts before posting this one, but I didn't find anything.


-- 
Bruno Medeiros - MSc in CS/E student
http://www.prowiki.org/wiki4d/wiki.cgi?BrunoMedeiros#D