Caching the System time
Helllo Snap maintainers! We are finally getting around to implementing a robust logging solution within Yesod. This creates the issue of having to frequently access the system time. I see that Snap has a separate thread to get the system time and cache the result [1]. Are you happy with this implementation? Can it be placed in a separate package and shared between web frameworks? Thanks, Greg Weber [1] http://hackage.haskell.org/packages/archive/snap-server/0.2.2/doc/html/src/S...
I thought the system time is already cached in user space. We get the system time twice per event manager loop in the RTS already and haven't seen any problems. On Fri, Aug 5, 2011 at 10:57 AM, Greg Weber <greg@gregweber.info> wrote:
Helllo Snap maintainers! We are finally getting around to implementing a robust logging solution within Yesod. This creates the issue of having to frequently access the system time. I see that Snap has a separate thread to get the system time and cache the result [1]. Are you happy with this implementation? Can it be placed in a separate package and shared between web frameworks? Thanks, Greg Weber [1] http://hackage.haskell.org/packages/archive/snap-server/0.2.2/doc/html/src/S... _______________________________________________ web-devel mailing list web-devel@haskell.org http://www.haskell.org/mailman/listinfo/web-devel
On Fri, Aug 5, 2011 at 7:57 AM, Greg Weber <greg@gregweber.info> wrote:
We are finally getting around to implementing a robust logging solution within Yesod. This creates the issue of having to frequently access the system time. I see that Snap has a separate thread to get the system time and cache the result [1].
That is an absurd non-optimisation. It costs just a few dozen nanoseconds to get the time of day under OS X, and Linux should be even cheaper since it doesn't involve a system call. It wouldn't surprise me if the approach above is actually *slower*.
Thanks, that is good to know! Eventually we may look into caching just the string for the logger that is generated from the time, but will be sure to do some bench-marking first. On Fri, Aug 5, 2011 at 10:47 AM, Bryan O'Sullivan <bos@serpentine.com>wrote:
On Fri, Aug 5, 2011 at 7:57 AM, Greg Weber <greg@gregweber.info> wrote:
We are finally getting around to implementing a robust logging solution within Yesod. This creates the issue of having to frequently access the system time. I see that Snap has a separate thread to get the system time and cache the result [1].
That is an absurd non-optimisation. It costs just a few dozen nanoseconds to get the time of day under OS X, and Linux should be even cheaper since it doesn't involve a system call. It wouldn't surprise me if the approach above is actually *slower*.
FWIW: we don't cache the system time because it's slow to *get* it -- we cache it because it's slow to turn it into a text string (for HTTP responses, logging, etc). It still may be a stupid thing to do, but it benchmarked faster when I wrote it. G On Fri, Aug 5, 2011 at 7:47 PM, Bryan O'Sullivan <bos@serpentine.com> wrote:
On Fri, Aug 5, 2011 at 7:57 AM, Greg Weber <greg@gregweber.info> wrote:
We are finally getting around to implementing a robust logging solution within Yesod. This creates the issue of having to frequently access the system time. I see that Snap has a separate thread to get the system time and cache the result [1].
That is an absurd non-optimisation. It costs just a few dozen nanoseconds to get the time of day under OS X, and Linux should be even cheaper since it doesn't involve a system call. It wouldn't surprise me if the approach above is actually *slower*.
_______________________________________________ web-devel mailing list web-devel@haskell.org http://www.haskell.org/mailman/listinfo/web-devel
-- Gregory Collins <greg@gregorycollins.net>
On Sat, Aug 6, 2011 at 9:18 AM, Gregory Collins <greg@gregorycollins.net>wrote:
FWIW: we don't cache the system time because it's slow to *get* it -- we cache it because it's slow to turn it into a text string (for HTTP responses, logging, etc). It still may be a stupid thing to do, but it benchmarked faster when I wrote it.
Ah - thanks for the clarification.
Without having delved into the issue in any great depth, I had a possible idea on this point. How about storing an IORef containing a time and the text representations you need. Whenever you need to get the time, compare the time in the IORef with the current time, and if they're different, update appropriately. Bonus points: store in an unpacked datatype and use a Builder instead of String. Would this (in theory) work? On Sat, Aug 6, 2011 at 7:18 PM, Gregory Collins <greg@gregorycollins.net> wrote:
FWIW: we don't cache the system time because it's slow to *get* it -- we cache it because it's slow to turn it into a text string (for HTTP responses, logging, etc). It still may be a stupid thing to do, but it benchmarked faster when I wrote it. G
On Fri, Aug 5, 2011 at 7:47 PM, Bryan O'Sullivan <bos@serpentine.com> wrote:
On Fri, Aug 5, 2011 at 7:57 AM, Greg Weber <greg@gregweber.info> wrote:
We are finally getting around to implementing a robust logging solution within Yesod. This creates the issue of having to frequently access the system time. I see that Snap has a separate thread to get the system time and cache the result [1].
That is an absurd non-optimisation. It costs just a few dozen nanoseconds to get the time of day under OS X, and Linux should be even cheaper since it doesn't involve a system call. It wouldn't surprise me if the approach above is actually slower. _______________________________________________ web-devel mailing list web-devel@haskell.org http://www.haskell.org/mailman/listinfo/web-devel
-- Gregory Collins <greg@gregorycollins.net>
_______________________________________________ web-devel mailing list web-devel@haskell.org http://www.haskell.org/mailman/listinfo/web-devel
extra bonus points: use Kazu's http-date package [1]. Actually, from Kazu's reports most of the benefit from the caching is likely due to avoiding creating the string with haskell's current date libraries. [1] http://hackage.haskell.org/packages/archive/http-date/0.0.0/doc/html/Network... On Sat, Aug 6, 2011 at 11:11 AM, Michael Snoyman <michael@snoyman.com>wrote:
Without having delved into the issue in any great depth, I had a possible idea on this point. How about storing an IORef containing a time and the text representations you need. Whenever you need to get the time, compare the time in the IORef with the current time, and if they're different, update appropriately. Bonus points: store in an unpacked datatype and use a Builder instead of String. Would this (in theory) work?
On Sat, Aug 6, 2011 at 7:18 PM, Gregory Collins <greg@gregorycollins.net> wrote:
FWIW: we don't cache the system time because it's slow to *get* it -- we cache it because it's slow to turn it into a text string (for HTTP responses, logging, etc). It still may be a stupid thing to do, but it benchmarked faster when I wrote it. G
On Fri, Aug 5, 2011 at 7:47 PM, Bryan O'Sullivan <bos@serpentine.com> wrote:
On Fri, Aug 5, 2011 at 7:57 AM, Greg Weber <greg@gregweber.info> wrote:
We are finally getting around to implementing a robust logging solution within Yesod. This creates the issue of having to frequently access the system time. I see that Snap has a separate thread to get the system
time
and cache the result [1].
That is an absurd non-optimisation. It costs just a few dozen nanoseconds to get the time of day under OS X, and Linux should be even cheaper since it doesn't involve a system call. It wouldn't surprise me if the approach above is actually slower. _______________________________________________ web-devel mailing list web-devel@haskell.org http://www.haskell.org/mailman/listinfo/web-devel
-- Gregory Collins <greg@gregorycollins.net>
_______________________________________________ web-devel mailing list web-devel@haskell.org http://www.haskell.org/mailman/listinfo/web-devel
_______________________________________________ web-devel mailing list web-devel@haskell.org http://www.haskell.org/mailman/listinfo/web-devel
On Sat, Aug 6, 2011 at 8:11 PM, Michael Snoyman <michael@snoyman.com> wrote:
Without having delved into the issue in any great depth, I had a possible idea on this point. How about storing an IORef containing a time and the text representations you need. Whenever you need to get the time, compare the time in the IORef with the current time, and if they're different, update appropriately. Bonus points: store in an unpacked datatype and use a Builder instead of String. Would this (in theory) work?
We do something similar to this, except we get the thread to recompute the date -- otherwise every second you have a race condition possibility where multiple threads compete to write the new thread into the IORef. If there's no activity, the date thread goes to sleep, the code to get the current date notices that the date is stale, and then it wakes the thread and recomputes the new date itself. Again, I'm not sure if it's worth it in the general case, but during periods of high load I think it helps to get as much stuff out of the processing threads as possible. G -- Gregory Collins <greg@gregorycollins.net>
couldn't tryTakeMVar and tryPutMVar handle this case of multiple writers well? I am asking because I really don't know :) On Sat, Aug 6, 2011 at 2:05 PM, Gregory Collins <greg@gregorycollins.net>wrote:
On Sat, Aug 6, 2011 at 8:11 PM, Michael Snoyman <michael@snoyman.com>wrote:
Without having delved into the issue in any great depth, I had a possible idea on this point. How about storing an IORef containing a time and the text representations you need. Whenever you need to get the time, compare the time in the IORef with the current time, and if they're different, update appropriately. Bonus points: store in an unpacked datatype and use a Builder instead of String. Would this (in theory) work?
We do something similar to this, except we get the thread to recompute the date -- otherwise every second you have a race condition possibility where multiple threads compete to write the new thread into the IORef. If there's no activity, the date thread goes to sleep, the code to get the current date notices that the date is stale, and then it wakes the thread and recomputes the new date itself. Again, I'm not sure if it's worth it in the general case, but during periods of high load I think it helps to get as much stuff out of the processing threads as possible.
G -- Gregory Collins <greg@gregorycollins.net>
_______________________________________________ web-devel mailing list web-devel@haskell.org http://www.haskell.org/mailman/listinfo/web-devel
Not really. tryTakeMVar and tryPutMVar are pretty heavyweight and involve taking a mutex lock: http://hackage.haskell.org/trac/ghc/browser/rts/PrimOps.cmm#L1440 IORef is much lighter-weight, see e.g. atomicModifyMutVar#: http://hackage.haskell.org/trac/ghc/browser/rts/PrimOps.cmm#L253 and readMutVar# / writeMutVar#: http://hackage.haskell.org/trac/ghc/browser/compiler/codeGen/CgPrimOp.hs#L12... The readMutVar primop just does a read (which turns into a small number of assembly instructions), and the writeMutVar primop just does a store and then marks the location dirty in the garbage collector. Doing an atomicModifyMutVar# involves a CAS which is also typically cheaper than mutex locking (you spin-loop instead of doing blocking/wakeup semantics). For the Snap date-caching code, we only mess with mutex locks if the date thread has been idle for a couple of seconds, in which case we don't mind paying the overhead of doing the locking. It's the "X hundred/thousand QPS" case we're trying to optimize. G On Sun, Aug 7, 2011 at 12:20 AM, Greg Weber <greg@gregweber.info> wrote:
couldn't tryTakeMVar and tryPutMVar handle this case of multiple writers well? I am asking because I really don't know :)
On Sat, Aug 6, 2011 at 2:05 PM, Gregory Collins <greg@gregorycollins.net>wrote:
On Sat, Aug 6, 2011 at 8:11 PM, Michael Snoyman <michael@snoyman.com>wrote:
Without having delved into the issue in any great depth, I had a possible idea on this point. How about storing an IORef containing a time and the text representations you need. Whenever you need to get the time, compare the time in the IORef with the current time, and if they're different, update appropriately. Bonus points: store in an unpacked datatype and use a Builder instead of String. Would this (in theory) work?
We do something similar to this, except we get the thread to recompute the date -- otherwise every second you have a race condition possibility where multiple threads compete to write the new thread into the IORef. If there's no activity, the date thread goes to sleep, the code to get the current date notices that the date is stale, and then it wakes the thread and recomputes the new date itself. Again, I'm not sure if it's worth it in the general case, but during periods of high load I think it helps to get as much stuff out of the processing threads as possible.
G -- Gregory Collins <greg@gregorycollins.net>
_______________________________________________ web-devel mailing list web-devel@haskell.org http://www.haskell.org/mailman/listinfo/web-devel
-- Gregory Collins <greg@gregorycollins.net>
When I measured it, gettimeofday/clock_gettime took less than a microsecond. Make sure the overhead of having a dedicated thread for time caching doesn't slow things down. My test was on x86 Linux on some 2009 Intel Xeon. Sent from my Android, please excuse the brevity. Am 08.08.2011 14:25 schrieb "Gregory Collins" <greg@gregorycollins.net>:
Not really. tryTakeMVar and tryPutMVar are pretty heavyweight and involve taking a mutex lock:
http://hackage.haskell.org/trac/ghc/browser/rts/PrimOps.cmm#L1440
IORef is much lighter-weight, see e.g.
atomicModifyMutVar#: http://hackage.haskell.org/trac/ghc/browser/rts/PrimOps.cmm#L253
and
readMutVar# / writeMutVar#:
http://hackage.haskell.org/trac/ghc/browser/compiler/codeGen/CgPrimOp.hs#L12...
The readMutVar primop just does a read (which turns into a small number of assembly instructions), and the writeMutVar primop just does a store and then marks the location dirty in the garbage collector. Doing an atomicModifyMutVar# involves a CAS which is also typically cheaper than mutex locking (you spin-loop instead of doing blocking/wakeup semantics).
For the Snap date-caching code, we only mess with mutex locks if the date thread has been idle for a couple of seconds, in which case we don't mind paying the overhead of doing the locking. It's the "X hundred/thousand
QPS"
case we're trying to optimize.
G
On Sun, Aug 7, 2011 at 12:20 AM, Greg Weber <greg@gregweber.info> wrote:
couldn't tryTakeMVar and tryPutMVar handle this case of multiple writers well? I am asking because I really don't know :)
On Sat, Aug 6, 2011 at 2:05 PM, Gregory Collins <greg@gregorycollins.net wrote:
On Sat, Aug 6, 2011 at 8:11 PM, Michael Snoyman <michael@snoyman.com wrote:
Without having delved into the issue in any great depth, I had a possible idea on this point. How about storing an IORef containing a time and the text representations you need. Whenever you need to get the time, compare the time in the IORef with the current time, and if they're different, update appropriately. Bonus points: store in an unpacked datatype and use a Builder instead of String. Would this (in theory) work?
We do something similar to this, except we get the thread to recompute the date -- otherwise every second you have a race condition possibility where multiple threads compete to write the new thread into the IORef. If there's no activity, the date thread goes to sleep, the code to get the current date notices that the date is stale, and then it wakes the thread and recomputes the new date itself. Again, I'm not sure if it's worth it in the general case, but during periods of high load I think it helps to get as much stuff out of the processing threads as possible.
G -- Gregory Collins <greg@gregorycollins.net>
_______________________________________________ web-devel mailing list web-devel@haskell.org http://www.haskell.org/mailman/listinfo/web-devel
-- Gregory Collins <greg@gregorycollins.net>
On Mon, Aug 8, 2011 at 2:41 PM, Aristid Breitkreuz <aristidb@googlemail.com> wrote:
When I measured it, gettimeofday/clock_gettime took less than a microsecond. Make sure the overhead of having a dedicated thread for time caching doesn't slow things down. My test was on x86 Linux on some 2009 Intel Xeon.
Again -- we're not caching for the time of day, we're caching the generated string representation (i.e. "Mon, 08 Aug 2011 12:49:05 GMT"). This string is sent with every HTTP response and it only changes once per second; the overhead involved with waking up and scheduling the green thread which updates this value would be completely dominated by the number of cycles spent generating this string 1,000 times per second. There is an argument to be made that instead of a dedicated clock update thread, every thread should: * call gettimeofday() * read an IORef-cached version to check if the current value is stale * if not, read the cached IORef string representation * if so, generate the necessary string representations (there are several) and write them into IORef caches There's a small risk of generating the string representations twice in this case, so we elected not to do it -- but actually I just realized we're not doing this properly. :( We're calling "tryPutMVar" in the inner loop -- that should probably be a "writeIORef" there, with the tryPutMVar moved into the "when old" branch. I guess I wrote this before I realized how expensive tryPutMVar was :( G -- Gregory Collins <greg@gregorycollins.net>
participants (6)
-
Aristid Breitkreuz -
Bryan O'Sullivan -
Greg Weber -
Gregory Collins -
Johan Tibell -
Michael Snoyman