On Mon, Jul 30, 2012 at 3:27 PM, John Dennis <jden...@redhat.com> wrote: > Stephen finally got his server patched with my timing instrumentation. He > sent me his log file and I ran my script to parse it. The results are quite > interesting. > > Basically I timed two things > > cmd_duration is the elapsed time to execute the IPA command. > > json_duration is the elapsed time to execute the JSON RPC containing the IPA > command. The difference (delta) between the two is the time we spend doing > "session bookkeeping". In all but the first RPC we were executing from the > session cache. Results are below. > > What is interesting is every command that executes from the session cache > seems to have about a 1.5 second constant overhead. The other interesting > bits are that most commands in the server execute quickly (from under a > tenth of second to .3 second) and on average the server takes 1.5 seconds to > respond to RPC (of which most of it appears to be in session code). > > What is taking so long with session bookkeeping? I don't know yet. I would > need more timing instrumentation. I will say when I looked at the > python-krb5 code (which we use to populate the ccache from the session and > read back to store in the session) seemed to be remarkably inefficient. We > also elected to use file based ccache rather than in-memory ccache (that > means there is a bit of file-IO occurring).
Just out of curiosity, were any, or, all of these, changes from the way things were handled in 2.1? > Has anyone used a Python profiler? Would that be better than adding > instrumentation? > > BTW, the actual commands were stripped to protect data anonymity. > > cmd_duration: 0.107673 json_duration: 3.176758 delta: 3.069085 > cmd_duration: 0.020068 json_duration: 1.543135 delta: 1.523067 > cmd_duration: 0.387210 json_duration: 1.802954 delta: 1.415744 > cmd_duration: 0.024086 json_duration: 1.405276 delta: 1.381190 > cmd_duration: 0.342808 json_duration: 1.950365 delta: 1.607557 > cmd_duration: 0.019286 json_duration: 1.398786 delta: 1.379500 > cmd_duration: 0.200895 json_duration: 1.754358 delta: 1.553463 > cmd_duration: 0.020293 json_duration: 1.410701 delta: 1.390408 > cmd_duration: 0.383433 json_duration: 1.819478 delta: 1.436045 > cmd_duration: 0.020350 json_duration: 1.406038 delta: 1.385688 > cmd_duration: 0.346864 json_duration: 1.771281 delta: 1.424417 > cmd_duration: 0.015998 json_duration: 1.707743 delta: 1.691745 > cmd_duration: 0.314527 json_duration: 1.730894 delta: 1.416367 > cmd_duration: 0.025323 json_duration: 1.582828 delta: 1.557505 Steve _______________________________________________ Freeipa-devel mailing list Freeipa-devel@redhat.com https://www.redhat.com/mailman/listinfo/freeipa-devel