Moodle
  1. Moodle
  2. MDL-15030

Quiz time taken incorrect by huge margin - millions of days!

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Minor Minor
    • Resolution: Duplicate
    • Affects Version/s: 1.8.2
    • Fix Version/s: None
    • Component/s: Quiz
    • Labels:
      None
    • Environment:
      Linux, Apache server
    • Database:
      MySQL
    • Affected Branches:
      MOODLE_18_STABLE
    • Rank:
      12564

      Description

      Quiz displays millions of days for time taken in a quiz attempt. See attached screenshot.

      1. odd time screenshot.jpg
        273 kB
      2. screenshot-1.jpg
        208 kB
      3. time_taken.gif
        42 kB

        Issue Links

          Activity

          Hide
          Tim Hunt added a comment -

          I agree that is somewhat remarkable, but actually there is a logical explanation.

          That time interval is about 2^64 seconds.

          Now, in 64-bit two's compliment binary arithmetic, if you start with an a small negative number -x, and treat it as an unsigned int, you get 2^64-x.

          So what actually happened is that the start time for the attempt was after the stop time, which is, of course, impossible - and Moodle's format_time function must produce weird results like this when given a negative time.

          So, how did the start time before stop time situation arise?

          Do you, by any chance, use several load-balanced web servers? And if so, are their clocks properly synchronised?

          Show
          Tim Hunt added a comment - I agree that is somewhat remarkable, but actually there is a logical explanation. That time interval is about 2^64 seconds. Now, in 64-bit two's compliment binary arithmetic, if you start with an a small negative number -x, and treat it as an unsigned int, you get 2^64-x. So what actually happened is that the start time for the attempt was after the stop time, which is, of course, impossible - and Moodle's format_time function must produce weird results like this when given a negative time. So, how did the start time before stop time situation arise? Do you, by any chance, use several load-balanced web servers? And if so, are their clocks properly synchronised?
          Hide
          Jason Hando added a comment -

          Hi Tim.... thanks for the explanation.

          not sure how it arose. It was a single anomaly inside a quiz attempted by several students. It only occurred, as you can see in the screenshot, for one attempt. Strange. It hasn't happened before, and may not happen again. Just thought it was worth reporting.

          The site in question does not use several load-balanced server... it is a school that has a single Moodle server running Linux, Apache, MySQL, PHP:

          Moodle 1.8.2 (2007021520)
          PHP Version 5.2.0
          MySQL 5.0.33

          Show
          Jason Hando added a comment - Hi Tim.... thanks for the explanation. not sure how it arose. It was a single anomaly inside a quiz attempted by several students. It only occurred, as you can see in the screenshot, for one attempt. Strange. It hasn't happened before, and may not happen again. Just thought it was worth reporting. The site in question does not use several load-balanced server... it is a school that has a single Moodle server running Linux, Apache, MySQL, PHP: Moodle 1.8.2 (2007021520) PHP Version 5.2.0 MySQL 5.0.33
          Hide
          Tim Hunt added a comment -

          Well, it is certainly very weird. Since it is a single anomaly, and we don't know how it happened, I am going to resolve this bug as 'cannot reproduce' for now. However, if you (or anyone else) encounters this again, I'll reopen the bug and investigate further.

          Show
          Tim Hunt added a comment - Well, it is certainly very weird. Since it is a single anomaly, and we don't know how it happened, I am going to resolve this bug as 'cannot reproduce' for now. However, if you (or anyone else) encounters this again, I'll reopen the bug and investigate further.
          Hide
          Jeffrey Silverman added a comment -

          I have had a report of this same thing.

          Notes:

          1) Moodle Version 1.9.3+ ( $release = '1.9.3+ (Build: 20081216)'; // Human-friendly version name)

          2) The value in the Time Taken column is exactly the same as reported by op. Indication to me that this could be something along the lines of a divide by zero, or similar to getting dec 31, 1969 when timetamps are set to -1.

          3) We do use several webservers, load balanced. But I can confirm that they are very tightly time-synchronized, to the second.

          More details as I get 'em...

          Show
          Jeffrey Silverman added a comment - I have had a report of this same thing. Notes: 1) Moodle Version 1.9.3+ ( $release = '1.9.3+ (Build: 20081216)'; // Human-friendly version name) 2) The value in the Time Taken column is exactly the same as reported by op. Indication to me that this could be something along the lines of a divide by zero, or similar to getting dec 31, 1969 when timetamps are set to -1. 3) We do use several webservers, load balanced. But I can confirm that they are very tightly time-synchronized, to the second. More details as I get 'em...
          Hide
          Tim Hunt added a comment -

          The number of days is the number of days when you convert (2^32 - something small) seconds to days (or is it ^64?). That is why it is always the same, as long as something small is less than one day.

          If you look in the database, you will probably find that timefinish for this attempt is less than timestart.

          Anything you can do to work out how that happened would be greatly appreciated.

          I guess I could hack in some code to stop these funny times being displayed, but I would much rather leave the problem visible until we have tracked down the cause and fixed it.

          (If you want a quick fix, running

          UPDATE mdl_quiz_attempt SET timefinish = timestart + 1 WHERE timefinish < timestart;

          is probably safe, but backup first, and proceed very cautiously.)

          Show
          Tim Hunt added a comment - The number of days is the number of days when you convert (2^32 - something small) seconds to days (or is it ^64?). That is why it is always the same, as long as something small is less than one day. If you look in the database, you will probably find that timefinish for this attempt is less than timestart. Anything you can do to work out how that happened would be greatly appreciated. I guess I could hack in some code to stop these funny times being displayed, but I would much rather leave the problem visible until we have tracked down the cause and fixed it. (If you want a quick fix, running UPDATE mdl_quiz_attempt SET timefinish = timestart + 1 WHERE timefinish < timestart; is probably safe, but backup first, and proceed very cautiously.)
          Hide
          Lori Davies added a comment -

          This issue has also been reported in v 1.9.7. I noticed that in both cases, the start and end time for the quiz was exactly the same at least down to the minute. Screenshot is attached.

          Show
          Lori Davies added a comment - This issue has also been reported in v 1.9.7. I noticed that in both cases, the start and end time for the quiz was exactly the same at least down to the minute. Screenshot is attached.
          Hide
          Nyle Spoelstra added a comment -

          This is the "huge time taken" number. You see the start and stop times are almost the same. Also the time taken is the same (large) number in both cases.

          Show
          Nyle Spoelstra added a comment - This is the "huge time taken" number. You see the start and stop times are almost the same. Also the time taken is the same (large) number in both cases.
          Hide
          Tim Hunt added a comment -

          Ah, this is a duplicate of MDL-21111 which I fixed last week. (Well, chronologically speaking, MDL-21111 is a duplicate of this bug.

          So, update to 1.9.9+ or 1.9.10 when it is released.

          Show
          Tim Hunt added a comment - Ah, this is a duplicate of MDL-21111 which I fixed last week. (Well, chronologically speaking, MDL-21111 is a duplicate of this bug. So, update to 1.9.9+ or 1.9.10 when it is released.

            People

            • Votes:
              1 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: