Battling time leaks

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

Battling time leaks

Joel Reymont
Folks,

It looks like I successfully squashed my time leaks and moving my  
serialization to Ptr Word8 got me as close to the metal as possible.  
I'm still getting wierd results, though, and they look like a time leak.

ORANGE ALERT: 0s, 6s, SrvServerInfo
ORANGE ALERT: 0s, 8s, SrvServerInfo
ORANGE ALERT: 0s, 9s, SrvServerInfo
ORANGE ALERT: 0s, 9s, SrvServerInfo
ORANGE ALERT: 0s, 7s, SrvServerInfo

unstuff :: Ptr Word8 -> Int -> IO Command
unstuff ptr ix =
     do TOD time1 _ <- getClockTime
        (kind, ix1) <- unpickle puCmdType ptr ix
        TOD time2 _ <- getClockTime
        (cmd', _) <- unpickle (puCommand kind) ptr ix1
        TOD time3 _ <- getClockTime
        when (time3 - time1 > 3) $
        -- fail here with the messages above

I would like to know where the time is going but how do I  
troubleshoot something like this?

My understanding is that regular profiling will give me the total  
time spent by cost-center so if I add cost-center annotations it will  
not give me the average time per run.

Come to think about it, the profiling report gives me the # of  
entries and the total time so I can get the average. Any other  
suggestions on how to figure out what is going on here?

        Thanks, Joel

--
http://wagerlabs.com/





_______________________________________________
Haskell-Cafe mailing list
[hidden email]
http://www.haskell.org/mailman/listinfo/haskell-cafe
Reply | Threaded
Open this post in threaded view
|

Re: Battling time leaks

Joel Reymont
These are the stats with -O2:

COST CENTRE                    MODULE               %time %alloc
read                           Script.PokerClient    20.1   13.6
timestamp                      Script.Trace          12.0    5.7
unstuff                        Script.PokerClient     8.0    4.4
puTableInfo                    Script.PicklePlus      6.9    6.4
trace_                         Script.Trace           5.6    1.5
readQ                          Script.Queue           5.0   21.3
reverse_                       Script.Endian          4.9    2.0
writeQ                         Script.Queue           4.9    4.4
wrap                           Script.Pickle          4.6    1.9
dispatch                       Script.Engine          4.3    2.8
unpickle                       Script.Pickle          3.8    0.5
lift                           Script.Pickle          2.9    4.5
appU_wstr                      Script.Endian          2.6    2.4
storable                       Script.Pickle          2.2    3.1
doSSLHandshake                 Script.PokerClient     1.1    0.0
fetch                          Script.Engine          1.0   18.9
dispatch_                      Script.Engine          1.0    0.2
pair                           Script.Pickle          0.9    1.2
post_                          Script.Engine          0.4    2.8

On Dec 20, 2005, at 11:01 AM, Joel Reymont wrote:

> Folks,
>
> It looks like I successfully squashed my time leaks and moving my  
> serialization to Ptr Word8 got me as close to the metal as  
> possible. I'm still getting wierd results, though, and they look  
> like a time leak.
>
> ORANGE ALERT: 0s, 6s, SrvServerInfo
> ORANGE ALERT: 0s, 8s, SrvServerInfo
> ORANGE ALERT: 0s, 9s, SrvServerInfo
> ORANGE ALERT: 0s, 9s, SrvServerInfo
> ORANGE ALERT: 0s, 7s, SrvServerInfo
>
> unstuff :: Ptr Word8 -> Int -> IO Command
> unstuff ptr ix =
>     do TOD time1 _ <- getClockTime
>        (kind, ix1) <- unpickle puCmdType ptr ix
>        TOD time2 _ <- getClockTime
>        (cmd', _) <- unpickle (puCommand kind) ptr ix1
>        TOD time3 _ <- getClockTime
>        when (time3 - time1 > 3) $
> -- fail here with the messages above

--
http://wagerlabs.com/





_______________________________________________
Haskell-Cafe mailing list
[hidden email]
http://www.haskell.org/mailman/listinfo/haskell-cafe
Reply | Threaded
Open this post in threaded view
|

Re: Re: Battling time leaks

Bulat Ziganshin
Hello Joel,

Tuesday, December 20, 2005, 3:38:17 PM, you wrote:

>> It looks like I successfully squashed my time leaks and moving my
>> serialization to Ptr Word8 got me as close to the metal as  
>> possible. I'm still getting wierd results, though, and they look  
>> like a time leak.
>>
>> ORANGE ALERT: 0s, 6s, SrvServerInfo

can you say what it exactly means? we are not mastered in your code.
some common explanation like "my program takes 6 seconds to
deserialize 50kb of data on Pentium4/3ghz" will be more understabdable

if your current problem is deserialization speed, i can give you my
own library. it now runs about 500kb/sec on 1ghz processor


--
Best regards,
 Bulat                            mailto:[hidden email]



_______________________________________________
Haskell-Cafe mailing list
[hidden email]
http://www.haskell.org/mailman/listinfo/haskell-cafe
Reply | Threaded
Open this post in threaded view
|

Re: Re: Battling time leaks

Joel Reymont

On Dec 20, 2005, at 1:38 PM, Bulat Ziganshin wrote:

> can you say what it exactly means? we are not mastered in your code.
> some common explanation like "my program takes 6 seconds to
> deserialize 50kb of data on Pentium4/3ghz" will be more understabdable

That's why I posted the code at http://wagerlabs.com/timeleak.tgz

The alerts are issued when the time of unstuffing exceeds 3 seconds.

> if your current problem is deserialization speed, i can give you my
> own library. it now runs about 500kb/sec on 1ghz processor

My issue is that I 1) have about 250 records and 2) my wire format is  
different from the Haskell representation. Everything arrives to me  
little-endian, for example.

It looks like pickling is the bottleneck so I'm converting all the  
structures to Storable :(. In the meantime, I'm looking for suggestions.

Einar offered BinSer which lets me use a single spec for the record  
format, conversions included. See http://cs.helsinki.fi/u/ekarttun/ 
haskell/test.hs. I still can't figure out how I would go from a :+: b  
to Foo a b, though.

        Thanks, Joel

--
http://wagerlabs.com/





_______________________________________________
Haskell-Cafe mailing list
[hidden email]
http://www.haskell.org/mailman/listinfo/haskell-cafe
Reply | Threaded
Open this post in threaded view
|

Re[2]: Re: Battling time leaks

Bulat Ziganshin
Hello Joel,

Wednesday, December 21, 2005, 9:47:19 PM, you wrote:
>> can you say what it exactly means? we are not mastered in your code.
>> some common explanation like "my program takes 6 seconds to
>> deserialize 50kb of data on Pentium4/3ghz" will be more understabdable

JR> That's why I posted the code at http://wagerlabs.com/timeleak.tgz

JR> The alerts are issued when the time of unstuffing exceeds 3 seconds.

this says nothing to me. you must say

1) your end goal - say, "run 1000 threads each 3 seconds"
2) why you can't share result of one unpickling among all threads?
3) your computer
4) unpickling time for one 50kb record


>> if your current problem is deserialization speed, i can give you my
>> own library. it now runs about 500kb/sec on 1ghz processor

JR> My issue is that I 1) have about 250 records and 2) my wire format is  
JR> different from the Haskell representation. Everything arrives to me  
JR> little-endian, for example.

1) you can use TH (may be, Einar will help you. he already have TH
support in its own SerTH library). even without TH, writing Binary
instances, imho, is an order easier than writing pickler functions -
especially when you need only deserialiation :)
2) Binary library use network format (little-endian) on all platforms

but i'm absolutely not sure that your real problem is raw unpickling speed

JR> It looks like pickling is the bottleneck so I'm converting all the  
JR> structures to Storable :(. In the meantime, I'm looking for suggestions.

JR> Einar offered BinSer which lets me use a single spec for the record  
JR> format, conversions included. See http://cs.helsinki.fi/u/ekarttun/ 
JR> haskell/test.hs. I still can't figure out how I would go from a :+: b  
JR> to Foo a b, though.

interesting thing, i will look. i'm rewrote from scratch my serialization
library 2 times, and still want to fully rewrite it again :)

http://cs.helsinki.fi/u/ekarttun/haskell/test.hs

--
Best regards,
 Bulat                            mailto:[hidden email]



_______________________________________________
Haskell-Cafe mailing list
[hidden email]
http://www.haskell.org/mailman/listinfo/haskell-cafe