1

I'm trying to leverage class constructors and deconstructors to represent and format scope in my log files via the RAII idiom. Using a single #define, it prints "{" and increases the global indentation level so that the next logged line is printed at that indentation level.

LogScopeRAII is supposed to print the "}" and decrease the global indentation level naturally as it goes out of scope at the end of Foo(). However, the behavior I am seeing is that LogScopeRAII is deconstructed immediately after being constructed.

Hypothesis: I think the problem is that LogScopeRAII is being created on the RHS of the assignment (and thus anonymously?) and is being destroyed at the end of the line, but I'm not sure what to do about. I thought LOG_ANONYMOUS_VARIABLE in VSCOPE_F would have done the trick and caused it to stick around, but it isn't.

Question: How can I stop LogScopeRAII from being deconstructed until the calling function goes out of scope?

/* Header */
LogScopeRAII::LogScopeRAII(Verbosity verbosity, const char* file, unsigned line, const char* format, ...)
{
    // ...
    // print "{" and then increase an indentation global var
}

LogScopeRAII::~LogScopeRAII()
{
    // ...
    // print "}" and then decrease the indentation global var
}

#define LOG_ANOMYMOUS_VARIABLE(str) LOG_CONCAT(str, __LINE__)

#define VSCOPE_F(verbosity, ...) \
LogScopeRAII LOG_ANONYMOUS_VARIABLE(raii) = \
((verbosity) > verb_cutoff() ? LogScopeRAII() : LogScopeRAII{verbosity, __FILE__, __LINE__, __VA_ARGS__}

#define SCOPE_F(verbosity_name, ...) VSCOPE_F(Verbosity_ ## verbosity_name, __VA_ARGS__)

#define SCOPE_FUNCTION(INFO) SCOPE_F(verbosity_name, __FUNCTION__)

/* Implementation */
void Foo()
{
    SCOPE_FUNCTION(INFO) // print "{" and increase indentation
    for (size_t i = 0; i < 3; ++i)
    {
        // do work
        LOG(INFO, "Work logged");
    }
    // print "}" and decrease indentation
}

Desired output:

{ Foo()
    "Work Logged" // Note indentation
} 0.23 s: Foo()

EDIT: BOILED THE ISSUE DOWN

The crux of it is this: The ternary doesn't seem to be working.

This works:

LogScopeRAII a(LogScopeRAII{ Verbosity_INFO, __FILE__, static_cast<unsigned>(__LINE__), "" });

But this does not:

LogScopeRAII a(((Verbosity_INFO) > indent) ? LogScopeRAII() : LogScopeRAII{ Verbosity_INFO, __FILE__, static_cast<unsigned>(__LINE__), "" });

I get:

{
}
Work logged
Work logged
Work logged
}
constructCounter: 1
destructCounter: 2
Exiting...
Stradigos
  • 814
  • 1
  • 13
  • 29
  • 1
    Stuffing this in a macro at this point is a bit premature. Break it out in actual code and get it working the way you want it then ad macros as desired. – Captain Obvlious Dec 31 '16 at 00:11
  • See edit. Took your suggestion. Seems like a ternary isn't working? – Stradigos Dec 31 '16 at 22:54
  • 1
    Maybe LogScopeRAII's move construction are broken. The "working version" would hide the problem due to copy elision, but there is no copy elision with the conditional operator version. At the least there'll need to be code in the destructor to not emit the `}` if this is a temporary that's been moved out of, etc. – M.M Dec 31 '16 at 23:19
  • Wow this is actually a MSVC C++11 thing it seems. Works perfectly in GCC. I guess it doesn't cause a copy. See: http://stackoverflow.com/questions/22078029/why-does-the-ternary-operator-prevent-return-value-optimization and http://stackoverflow.com/questions/11914691/copy-elision-move-constructor-not-called-when-using-ternary-expression-in-retur – Stradigos Dec 31 '16 at 23:32
  • I was able to fix this by using static_cast in the macro. I'm just curious if you know of any other, or better, ways? – Stradigos Jan 01 '17 at 00:23

1 Answers1

1
#define VSCOPE_F(verbosity, ...) \
LogScopeRAII LOG_ANONYMOUS_VARIABLE(raii) = \
((verbosity) > verb_cutoff() ? LogScopeRAII() : LogScopeRAII{verbosity, __FILE__, __LINE__, __VA_ARGS__}

should be

#define VSCOPE_F(verbosity, ...) \
LogScopeRAII LOG_ANONYMOUS_VARIABLE(raii) \
(((verbosity) > verb_cutoff() ? LogScopeRAII() : LogScopeRAII{verbosity, __FILE__, __LINE__, __VA_ARGS__})

else you use copy constructor of temporary variable.

(You might also fix you move-constructor and destructor to allow your current MACRO)

Jarod42
  • 203,559
  • 14
  • 181
  • 302
  • This doesn't seem to make a difference. However, if I remove the ternary operation and just go with the LogScopeRAII with parameters it works. What could be wrong with the ternary? I confirmed it's evaluating to the same LogScopeRAII -- the one with parameters -- either way, so it's something else. It keeps constructing and deconstructing right away, and then deconstructing one more time at the end... which is weird, because there's not a matching constructor to go with it. Not sure how that's even possible. Here's a pastebin of my test setup: http://pastebin.com/8mSjVnPN – Stradigos Dec 31 '16 at 22:40
  • Ultimately, this is a MSVC C++14 issue because it works perfectly in GCC. I guess it doesn't cause a copy in GCC but does in MSVC. See: http://stackoverflow.com/questions/22078029/why-does-the-ternary-operator-prevent-return-value-optimization and http://stackoverflow.com/questions/11914691/copy-elision-move-constructor-not-called-when-using-ternary-expression-in-retur I added static_cast where appropriate to fix it. Curious if there's a better way, but the problem is solved nevertheless. Thank you for your help. – Stradigos Jan 01 '17 at 05:38