Moodle
  1. Moodle
  2. MDL-37585

Make $DB->set_debug(true) display the time taken to execute each query.

    Details

    • Type: Improvement Improvement
    • Status: Closed
    • Priority: Minor Minor
    • Resolution: Fixed
    • Affects Version/s: 2.4.1
    • Fix Version/s: 2.5
    • Component/s: Database SQL/XMLDB
    • Labels:
    • Testing Instructions:
      Hide

      Add $DB->set_debug(true); near the top of some script.

      Note that, as well as seeing all the SQL executed, you can also see the time each query took.

      Show
      Add $DB->set_debug(true); near the top of some script. Note that, as well as seeing all the SQL executed, you can also see the time each query took.
    • Affected Branches:
      MOODLE_24_STABLE
    • Fixed Branches:
      MOODLE_25_STABLE
    • Pull from Repository:
    • Pull Master Branch:
    • Rank:
      47239

      Description

      Summary says it all!

        Activity

        Hide
        Tim Hunt added a comment -

        OK, here it is.

        Dear integrators, I will let you decide which branches, if any, to cherry-pick this to.

        Show
        Tim Hunt added a comment - OK, here it is. Dear integrators, I will let you decide which branches, if any, to cherry-pick this to.
        Hide
        Petr Škoda added a comment -

        +1

        Show
        Petr Škoda added a comment - +1
        Hide
        Aparup Banerjee added a comment -

        This is cool!

        minor notes (for a very major class):

        • its always bugged me how a class's variable accessor function would be used within the very same class. In this case, old code print_debug() calls get_debug() which simply accesses $this->debug. The extra function context bugs me but i guess that my low level brain talking.. it really doesn't make much of a difference here as this is happening outside of patch too so i'm kiv-ing this for integration in my mind.
        • i'd backport this based on : code is isolated to debuggers , but i'll take an integrator vote just to be safe.
          *except for the one statement in query_end(), i'm thinking it'd be nice to have the 'microtime(true) - $this->last_time' calculation done only after $this->debug is checked to be true. This is so that production wouldn't have to go through the extra call (albeit a very small call) unnecessarily. yes, it would introduce more time to the reported query time but it would be a constant offset so the purpose would still be served. it is a protected function so calls will be from within the class, would it be too inflexible? what do you think?
        • (out of patch comment) query_end() has an unused $time var, it'd be great if you wouldn't mind verifying this and possibly clean this up.

        ok, i think i've typed more than the benefit it would serve, will await feedback.

        Happy New Year!

        Show
        Aparup Banerjee added a comment - This is cool! minor notes (for a very major class): its always bugged me how a class's variable accessor function would be used within the very same class. In this case, old code print_debug() calls get_debug() which simply accesses $this->debug. The extra function context bugs me but i guess that my low level brain talking.. it really doesn't make much of a difference here as this is happening outside of patch too so i'm kiv-ing this for integration in my mind. i'd backport this based on : code is isolated to debuggers , but i'll take an integrator vote just to be safe. *except for the one statement in query_end(), i'm thinking it'd be nice to have the 'microtime(true) - $this->last_time' calculation done only after $this->debug is checked to be true. This is so that production wouldn't have to go through the extra call (albeit a very small call) unnecessarily. yes, it would introduce more time to the reported query time but it would be a constant offset so the purpose would still be served. it is a protected function so calls will be from within the class, would it be too inflexible? what do you think? (out of patch comment) query_end() has an unused $time var, it'd be great if you wouldn't mind verifying this and possibly clean this up. ok, i think i've typed more than the benefit it would serve, will await feedback. Happy New Year!
        Hide
        Dan Poltawski added a comment -

        -1 to backport (we're being strict in this brave new world)

        Show
        Dan Poltawski added a comment - -1 to backport (we're being strict in this brave new world)
        Hide
        Damyon Wiese added a comment -

        Agree this is an improvement so -1 for backport.

        Show
        Damyon Wiese added a comment - Agree this is an improvement so -1 for backport.
        Hide
        Aparup Banerjee added a comment -

        why i was inclined to backport was also since performance improvements could be gained from the stable branches out there (with this patch), but i guess any development going on would most likely take place on master too.

        Show
        Aparup Banerjee added a comment - why i was inclined to backport was also since performance improvements could be gained from the stable branches out there (with this patch), but i guess any development going on would most likely take place on master too.
        Hide
        Tim Hunt added a comment -

        Updated MDL-37585 branch pushed. I think this new version is definitely better. Thanks for you comments Aparup.

        Show
        Tim Hunt added a comment - Updated MDL-37585 branch pushed. I think this new version is definitely better. Thanks for you comments Aparup.
        Hide
        Aparup Banerjee added a comment -

        cool! integrated into master only.

        ps: now i'm getting ideas for baseline query times as definitive DB related performance markers. we could even scatter chart this out and check for outliers.

        pps: i can't find any docs on the originally existing $DB->set_debug() so i'm going to mark this as docs_required for the docs tinkerers.

        Show
        Aparup Banerjee added a comment - cool! integrated into master only. ps: now i'm getting ideas for baseline query times as definitive DB related performance markers. we could even scatter chart this out and check for outliers. pps: i can't find any docs on the originally existing $DB->set_debug() so i'm going to mark this as docs_required for the docs tinkerers.
        Hide
        Rossiani Wijaya added a comment -

        This is working as expected.

        Test passed.

        Show
        Rossiani Wijaya added a comment - This is working as expected. Test passed.
        Hide
        Eloy Lafuente (stronk7) added a comment -

        Surely you will be happy to know that your code is now part of Moodle upstream. Thanks, thanks!

        Closing as fixed, ciao

        Show
        Eloy Lafuente (stronk7) added a comment - Surely you will be happy to know that your code is now part of Moodle upstream. Thanks, thanks! Closing as fixed, ciao
        Hide
        Mary Cooch added a comment -

        (Housekeeping)I'm just marking this as dev_docs required as I'm not sure how it could be referenced in user docs - please shout if I have missed something obvious.

        Show
        Mary Cooch added a comment - (Housekeeping)I'm just marking this as dev_docs required as I'm not sure how it could be referenced in user docs - please shout if I have missed something obvious.
        Hide
        Tim Hunt added a comment -

        Note added at http://docs.moodle.org/dev/Data_manipulation_API#Debug_fuctions. That seems as good as anything.

        Show
        Tim Hunt added a comment - Note added at http://docs.moodle.org/dev/Data_manipulation_API#Debug_fuctions . That seems as good as anything.

          People

          • Votes:
            0 Vote for this issue
            Watchers:
            8 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: