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:

      Description

      Summary says it all!

        Gliffy Diagrams

          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 Skoda added a comment -

          +1

          Show
          Petr Skoda 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: