« first day    last day (16 days later) » 

1:18 AM
Well, here's the results. I've created scenarios for direct vs. service queued, and simple string vs. variadic arguments. I've shown your implementations of things and mine. So you get the following list of cases:
build/nonius/direct-simple
build/nonius/direct-variadic
build/nonius/mine-simple
build/nonius/mine-variadic
build/nonius/service-simple
build/nonius/service-variadic
Notable conclusions: yes, the service reduces latency for "complex" variadic arguments only, but it increases jitter
In the simple cases (where the argument is a single string), my initial version seems faster (~92ns vs. ~125ns).
Most importantly the variation that uses an io_service queue and formats variadic arguments, is wrong: it crashes unless you keep the arguments around.
(This is something I mentioned in the 5th bullet of "Questionables" in my answer, but indeed if you put the arguments in local scope, things crash very quickly.)
So, actually you should not consider the service-options serious options. Instead I've added a demonstration of the thing I meant earlier: (let's call it the smart-lambda approach)
12 hours ago, by sehe
In that case it makes way more sense to store the "log promises" in the spsc queue directly
You didn't see what I meant, back then, so let me show: smart-lambda.cpp (and the timings downloads.sehe.nl/stackoverflow/q28254996/smart-lambda.html).
This method doesn't have the Undefined Behaviour (all arguments are copied¹) and is more flexible (you can even use manipulators like setw(12) or std::boolalpha). Of course, the copying is going to make it slower, but it is, indeed, still faster than formatting on the spot (compare with downloads.sehe.nl/stackoverflow/q28254996/mine-variadic.html)
Just for curiosity's sake, if you do the smart lambda trick and pass the arguments by reference (don't to this for the same reason that service_variadic is broken), then things are pretty fast indeed (127ns on average, instead of 318ns when copying).
The difference is obvious, and inevitable. Letting the caller do the formatting on push would be more expensive (~1037ns) so I have to admit this seems worth it if you want really low-latency logging.
All the code and revision are up on gist.github.com/sehe/54caed4b4cd7c9352174 (note that I fixed several minor issues with your versions, and 1 major issue where the pop() thread was running before the queue was created).
Aside: (I'd suggest looking at my code for ways to make the code simpler. In many many many ways. Code is for humans to read, and it's important to keep it simple)
¹ PS. all arguments are copied, unless they can't be, or when they decayed... This means the problem is still there in a-typical cases like: paste.ubuntu.com/10006567. On the bright side, the caller has a choice now, and it could even elect to capture /some/ arguments by reference if you know that to be safe (handy for e.g. std::string m_log_category;)
OH, I FORGOT The results are up here: downloads.sehe.nl/stackoverflow/q28254996
 
 
5 hours later…
7:23 AM
wow thanks a lot ! let me go through the stuff
 
Good morning
 
8:11 AM
morning, your smart lambda code works on my laptop, but not on my server (rhel 6.5 with gcc 4.4)
i fixed the problem you identified with the service setup
i basically do l.enqueue("hello",1,2,3,5.36," world\n");
template<typename T, typename ... Args>
inline __attribute__((always_inline))
void enqueue(T const & t, Args const & ... args){
std::atomic_fetch_add_explicit(&this->ctr,1,std::memory_order_release);
this->concatenate(t,args ...);
}
template <typename T, typename ... Args>
inline __attribute__((always_inline))
void concatenate(T t, Args ... args){
this->io_service->post(boost::bind(&Log::push,this,boost::bind(&Log::stringer<T const &, Args const & ...>,
this,boost::cref(t),boost::cref(args) ...)));
}
so the log info enteres enqueue by reference, then i pass a copy to concatenate after which it is offloaded onto the thread for stringing. On my server this after a warmup this clocks about 0 - 1 micro.
is there a way you can modify smart_lambda.cpp to work for gcc.4.4 please, so that i can compare on server
 
 
1 hour later…
9:25 AM
@AdityaSihag there is no way. At least not a user friendly way (without too much complexity)
 
and building gcc from source is an absolute nightmare !
 
unrelated, but yes!
woah - this->io_service->post(boost::bind(&Log::push,this,boost::bind(&Log::stringer<T const &, Args const & ...>, this,boost::cref(t),boost::cref(args) ...)));
your compiler... does it love you?
 
9:59 AM
... you work for NSE?
 
 
1 hour later…
11:13 AM
no no, I HFT on the nse :)
i managed to get a nanosecond pass-by-copy service version to work on the server ..
that crazy nested bind line turns out doesnt work with boost bind for more than 9 arguments .. i switched over to tr1 for that ... sheesh .. if only there was a straightforward way to build gcc-<any version>
 
12:07 PM
@AdityaSihag care to share?
 
12:43 PM
already did ! .. basically the code snippets i posted upstairs .. link @ coliru.stacked-crooked.com/a/89f619acc40f0feb
that's the version i run on my rhel 6.5 gcc 4.4 server
i will specialize the boost::lexical_cast for each of the typed conversions cause I know the default lexical cast implementation is slower than what is reasonably achievable
stackoverflow.com/questions/28274112/… --> that's the thread for boost::bind 9 argument limitation
 
 
1 hour later…
2:02 PM
@AdityaSihag Ah. So... not subnano then. Submicro I presume
NIce work. Few notes:
2. the atomic counter is not needed, you just need to shutdown the io_service correctly (this fix was in my samples, it was one of those "minor issues" I meant)
3. you .... messed up with the "fix" for copy-instead-of-reference. You copied them on the source thread, then passed the by ref to the ioservice... That's not an improvement /at all/. Make sure you do test for this in your testcases! It's too easy to get wrong, and too easy to not get flagged by e.g. valgrind.
1. make it simpler... :( downloads.sehe.nl/stackoverflow/q28254996/subnano.cpp (why all the atomics, scoped_ptr, new etc., extra template arguments)
That version linked contains all the suggested improvements, and the timings are updated (this time from my work machine, so they can't be compared to yesterday, but I've updated them all, so you can still compare between versions)
Still, excellent solution, if you can afford the heap pressure and spinning a thread at 100% for each BlitzLogger instance!
PS. in relation to 3. above you will have to keep watching out for the footnote:
12 hours ago, by sehe
¹ PS. all arguments are copied, unless they can't be, or when they decayed... This means the problem is still there in a-typical cases like: http://paste.ubuntu.com/10006567/. On the bright side, the caller has a choice now, and it could even elect to capture /some/ arguments by reference if you know that to be safe (handy for e.g. std::string m_log_category;)
It applies to your solution too. Note, that I think you can still let the caller do l.enqueue(boost::cref(m_logCategory)); if you're sure that there will not be a data race. This is actually pretty elegant.
@AdityaSihag I think that's old belief, though. Check the up-to-date implementation. Of course, lexical_cast<> has a contract to behave as-if stream insertion/extraction is performed
 
2:52 PM
yeah cores are in ample supply !
I've still not got my head around the decay part.
What do you mean by l.enqueue(boost::cref(m_logCategory)) ? Isn't the enqueue function already accepting its arguments by constant reference. What impact does this boost::cref have over and above that?
also if i remove the boost::ref (t), boost::ref(args) ..., and instead pass by value, then the code fails to compile with the most unreadable .hpp trace. so that is a problem
pass by value to the boost bind call
In file included from /usr/lib/gcc/x86_64-redhat-linux/4.4.6/../../../../include/c++/4.4.6/tr1/functional:56,
from /include/illuminati/dev_multi/connector.h:8,
from main.cpp:1:
/usr/lib/gcc/x86_64-redhat-linux/4.4.6/../../../../include/c++/4.4.6/tr1_impl/functional: In member function ‘typename std::tr1::result_of<_Functor(typename std::tr1::result_of<std::tr1::_Mu<_Bound_args, std::tr1::is_bind_expression::value, (std::tr1::is_placeholder::value > 0)>(_Bound_args, std::tr1::tuple<_UElements ...>)>::type ...)>::type std::tr1::_Bind<_Functor(_Bound_args ...)>::__call(const std::tr1::tuple<_U
that error comes if i simply replace the calls of std::tr1::ref(t), std::tr1::ref(args) ... with t,args ...
 
3:17 PM
@AdityaSihag it gets forwarded into the bind, which treats it specially (namely binding by ref, instead of by value)
@AdityaSihag Probably because you pass non-decaying stuff. Is that with the main() you supplied? I can take a look
@AdityaSihag You should, then, of course also change the enqueue signature to take Args const&... to avoid copying twice
 
int main(){

blitz::BlitzLogger<> l("/tmp/junk.log",15,15,1024);
struct timeval ts_1, ts_2;
gettimeofday(&ts_1,NULL);

for (int64_t i = 0; i < 10; ++i){
l.enqueue("hello",1,2,3,5.36," world\n");
}

gettimeofday(&ts_1,NULL);
{
for (int i = 0; i < 333333; ++i){
// l.enqueue("hello",42,32,45);
l.enqueue("check this out", 2, 4.3, "junk it\n");
l.enqueue("trade @ ", 100," for ", 42000,"sadadahares for instrument ", 4.3, "junk it\n",42);
l.enqueue("check thasdadis out", 2, 4.3, "junasdk it","trade @ ", 100," for ", 42000,
yes all functions are pass by reference now
let me paste the logger class here too
template <typename T, typename ... Args>
inline __attribute__((always_inline))
void enqueue(T const & t, Args const & ...args){
// std::cerr << __FUNCTION__ << " address of " << t << " is " << &t << std::endl;
_io_service.post(std::tr1::bind(&BlitzLogger::push,this,
std::tr1::bind(&BlitzLogger::stringer<T const &, Args const & ...>, this,
// t, args ...)));
boost::ref(t), boost::ref(args) ...)));
// concatenate(args ...);
}
that's the enqueue functions
i got rid of concatenate cause it wasn't doing anything special
but either way, the point is if i try passing to the bind object by copy, it doesn't compile
on gcc 4.4 i should highlight :(
 
@AdityaSihag Ah. I forgot that bind explicitly instantiates the stringer<> function template. So you need to "do the decay" for the compiler. With lambdas that gotcha doesn't occur (because overload invocation is ... just overload invocation :)). Fix:
        template <typename... Args> void concatenate(Args const&... args) {
            io_service.post(
                std::tr1::bind(&BlitzLogger::push, this,
                    std::tr1::bind(&BlitzLogger::stringer<typename boost::decay<Args const&>::type...>, this, args...)));
        }
You see the decay<>? That's it
@AdityaSihag Also, the fact that "I don't know how to solve this compiler error" sounds like a very poor reason to do the copy in another the wrong place :)
@AdityaSihag Does your company have money in ample supply? (To pay for the datacenter cooling bill) :)
@AdityaSihag (please consider not doing so ... It looks awful. There's gist, coliru, pastebin etc.)
 
wow !! i need to investigate what this decay stuff is .. never heard of it. Thank you so much ! i think the cooling is handled by the exchange co-location facility which is shared by all participants for a fixed fee :p
 
3:39 PM
48
Q: What is std::decay and when it should be used?

Eric Javier Hernandez SauraWhat are the reasons for the existence of std::decay? In what situations is std::decay useful?

I guess I won't mention how fixed fees work :)
 
haha
so that const char * that i'm passing on my enqueue function are safe under this setup ?
how long have you been programming c ++ ?
 
4:10 PM
@AdityaSihag ~15 years
@AdityaSihag Depends on what they point to. In your sample they're literals, so yes, they're guaranteed to be immutable. But, this:
2 hours ago, by sehe
12 hours ago, by sehe
¹ PS. all arguments are copied, unless they can't be, or when they decayed... This means the problem is still there in a-typical cases like: http://paste.ubuntu.com/10006567/. On the bright side, the caller has a choice now, and it could even elect to capture /some/ arguments by reference if you know that to be safe (handy for e.g. std::string m_log_category;)
is equally deadly for even though you pass it as char const*. The point is, const doesn't mean that the object cannot change. It means, it cannot be changed through that particular reference. But the object referred to (in this case, pointed to) might very well be changed elsewhere or cease to exist.
Both cases are
In computer programming, undefined behavior (UB) refers to computer code whose behavior is not specified under certain conditions. The behavior of some programming languages—most famously C and C++—is undefined in some cases. In the standards for these languages, the semantics of certain operations are undefined, so an implementation can assume that such operations never occur in standard-conforming program code, since the implementation will be correct whatever it does in such cases, analogous to don't-care terms in digital logic. This assumption can make various program transformations valid...
The only party who knows is the caller. You could prevent raw arrays from being passed, but this would preclude string literals... It's a judgement call
 
 
1 hour later…
5:41 PM
This prevention would be through a templatized static assert, right ?
What about thread safety of the enqueue function? The queue is obviously conforming to the spsc requirement.
You mentioned wrapping arguments to the enqueue in boost::ref, what would that do ?
 
5:58 PM
@AdityaSihag That, or sfinae. Anyways, the real point is, only the caller knows. The only tricky thing is users will usually not expect values to be teleported to another thread when they say "log.this_for_me(a,b,c,);".
So, it's hard to be this clever and still maintain the Pit Of Success API quality guideline
(Can you split up your messages? If you ask 4 questions in one post, it's really hard to answer them)
> You mentioned wrapping arguments to the enqueue in boost::ref, what would that do ?
3 hours ago, by sehe
@AdityaSihag it gets forwarded into the bind, which treats it specially (namely binding by ref, instead of by value)
Already answered :)
 
6:23 PM
O right right, the boost::ref is for bind object itself, n not for the subsequently called function. My brain needs rest I think !
So enqueue is thread safe, as in I can call log.enqueue from distinct threads right ?
 
6:34 PM
Yes. It's like the ActiveObject pattern (with one shot operations)
 
You are really knowledgeable, and helpful ! Thank you v much, I can learn a lot from you
 

« first day    last day (16 days later) »