Uploaded image for project: 'Moodle'
  1. Moodle
  2. MDL-56223

CLI Calendar Event Updated/Created bug affecting database/logs

    XMLWordPrintable

    Details

    • Testing Instructions:
      Hide

      Setup

      I recommend you having two separate browser windows for this test.

      • One for the calendar UI testing and the other one to monitor logs.
        • To open the log report log in as admin and go to Site administration > Reports > Logs
      1. You'll need to run SQL commands in your database.
      Skipped events testing
      1. Log in as admin and go to the calendar
      2. Click Manage subscriptions button and then fill the form with the following values:
      3. Enter Google as calendar name.
      4. For the Calendar URL field, enter the following URL of a public test Google calendar:

        https://calendar.google.com/calendar/ical/en.usa%23holiday%40group.v.calendar.google.com/public/basic.ics
        

      5. Under Type of event, choose User and then click Add button.
      6. Make sure you get the following results in the import summary:

        Events imported: 75
        Events skipped: 0
        Events updated: 0
        

        • Note there's a new Event skipped and it should be showing 0.
        • Make sure all events from Google's calendar have been imported (just check August and September, 2019 in the calendar. You should see some events there now).
      7. On window 2, click Get these logs button.
      8. You should see 75 new calendar event created events similar to the one bellow (of course ID will be different):

        The user with id '2' created the event 'Black Friday' with id '1240'.
        

      9. On window 1, go to Manage subscriptions again and click Update button.
      10. Make sure you get the following results in the import summary:

        Events imported: 0
        Events skipped: 75
        Events updated: 0
        

        • On window 2, make sure no calendar event update events has been triggered (logged).
      Testing subscription sync (updating events data)
      1. Open your database editor and run the following SQL command:

        SELECT id FROM mdl_event_subscriptions WHERE name = 'Google';
        

        Please make note of the ID number the query returned.

      1. Now, let's simulate an update to make sure events in moodle side are updated.
      2. Run the following SQL command:

        UPDATE mdl_event SET name = 'Testing MDL-56223' where subscriptionid = THENUMBERYOUMAKENOTE;
        

      3. On window 1, note all events previously added are now titled Testing MDL-56223.
      4. On same window, go to Manage subscriptions page and click Update button again.
      5. Make sure you get the following results in the import summary:

        Events imported: 0
        Events skipped: 0
        Events updated: 75
        

      6. On window 2, click Get these logs button again.
      7. Make sure 75 calendar event update events similar to the one bellow (of course, ID will be different) have been logged:

        The user with id '2' updated the event 'Black Friday' with id '1240'.
        

      Testing sync (event missing in the subscription iCal source)
      1. Let's simulate a scenario where an event has been removed from the iCal source (Google in this case) and this event needs to be removed on moodle side.
      2. Open calendar/lib.php and search for foreach ($ical->components['VEVENT'] as $event) {.
        • If you are looking on integration code should be around line 3034.
      3. Add this in the line above the foreach declaration (around line 3034):

        unset($ical->components['VEVENT'][0]);

      4. Save the file.
      5. In window 1 click Update button in the Manage subscription page.
      6. Make sure you get the following results in the import summary:

        Events deleted: 1
        Events imported: 0
        Events skipped: 74
        Events updated: 0
        

      7. On window 2 click Get these logs button.
      8. Make sure a single calendar event created event has been logged.
      9. Please remove that unset from the code and save.
      10. Run update once more from window 1 to make sure we have 75 events again.
      Testing calendar task events handling
      1. Open a terminal and go to the dir root of your integration instance
      2. Run the calendar_cron_task task using the following command:

        php admin/tool/task/cli/schedule_task.php --execute='\core\task\calendar_cron_task'
        

      3. On window 2, click Get these logs button again.
      4. Make sure no calendar event updated related events have been logged.
      5. Run the following SQL commands:

        UPDATE mdl_event SET name = 'Testing MDL-56223' WHERE subscriptionid = THENUMBERYOUMAKENOTE;
         
        UPDATE mdl_event_subscriptions SET pollinterval = 1 WHERE id = THENUMBERYOUMAKENOTE;
        

      6. On window 1 go to Calendar month view and note the events have been renamed to "Testing MDL-56223"
      7. Run calendar_cron_task again.
      8. On window 1 reload the calendar and make all event names have been updated to the correct title.
      9. On window 2 click Get these logs button again.
      10. Make sure a Calendar event updated event has been logged for each event (should be 75 events in total).
      11. Run calendar_cron_task again.
      12. Let's mark that subscription to be updated by changing the pollinterval value, for this run the SQL command:

        UPDATE mdl_event_subscriptions SET pollinterval = 1 WHERE id = THENUMBERYOUMAKENOTE;
        

      13. Run calendar_cron_task again.
      14. On window 2, click Get these logs.
      15. Make sure no new Calendar event updated has been logged.
      16. Make sure only a single Calendar subscription updated event has been logged.
      Show
      Setup I recommend you having two separate browser windows for this test. One for the calendar UI testing and the other one to monitor logs. To open the log report log in as admin and go to Site administration > Reports > Logs You'll need to run SQL commands in your database. Skipped events testing Log in as admin and go to the calendar Click Manage subscriptions button and then fill the form with the following values: Enter Google as calendar name . For the Calendar URL field, enter the following URL of a public test Google calendar: https://calendar.google.com/calendar/ical/en.usa%23holiday%40group.v.calendar.google.com/public/basic.ics Under Type of event , choose User and then click Add button. Make sure you get the following results in the import summary: Events imported: 75 Events skipped: 0 Events updated: 0 Note there's a new Event skipped and it should be showing 0 . Make sure all events from Google's calendar have been imported (just check August and September, 2019 in the calendar. You should see some events there now). On window 2 , click Get these logs button. You should see 75 new calendar event created events similar to the one bellow (of course ID will be different): The user with id '2' created the event 'Black Friday' with id '1240'. On window 1 , go to Manage subscriptions again and click Update button. Make sure you get the following results in the import summary: Events imported: 0 Events skipped: 75 Events updated: 0 On window 2 , make sure no calendar event update events has been triggered (logged). Testing subscription sync (updating events data) Open your database editor and run the following SQL command: SELECT id FROM mdl_event_subscriptions WHERE name = 'Google'; Please make note of the ID number the query returned. Now, let's simulate an update to make sure events in moodle side are updated. Run the following SQL command: UPDATE mdl_event SET name = 'Testing MDL-56223' where subscriptionid = THENUMBERYOUMAKENOTE; On window 1 , note all events previously added are now titled Testing MDL-56223 . On same window, go to Manage subscriptions page and click Update button again. Make sure you get the following results in the import summary: Events imported: 0 Events skipped: 0 Events updated: 75 On window 2 , click Get these logs button again. Make sure 75 calendar event update events similar to the one bellow (of course, ID will be different) have been logged: The user with id '2' updated the event 'Black Friday' with id '1240'. Testing sync (event missing in the subscription iCal source) Let's simulate a scenario where an event has been removed from the iCal source (Google in this case) and this event needs to be removed on moodle side. Open calendar/lib.php and search for foreach ($ical->components ['VEVENT'] as $event) { . If you are looking on integration code should be around line 3034 . Add this in the line above the foreach declaration (around line 3034): unset($ical->components['VEVENT'][0]); Save the file. In window 1 click Update button in the Manage subscription page. Make sure you get the following results in the import summary: Events deleted: 1 Events imported: 0 Events skipped: 74 Events updated: 0 On window 2 click Get these logs button. Make sure a single calendar event created event has been logged. Please remove that unset from the code and save. Run update once more from window 1 to make sure we have 75 events again. Testing calendar task events handling Open a terminal and go to the dir root of your integration instance Run the calendar_cron_task task using the following command: php admin/tool/task/cli/schedule_task.php --execute='\core\task\calendar_cron_task' On window 2 , click Get these logs button again. Make sure no calendar event updated related events have been logged. Run the following SQL commands: UPDATE mdl_event SET name = 'Testing MDL-56223' WHERE subscriptionid = THENUMBERYOUMAKENOTE;   UPDATE mdl_event_subscriptions SET pollinterval = 1 WHERE id = THENUMBERYOUMAKENOTE; On window 1 go to Calendar month view and note the events have been renamed to "Testing MDL-56223 " Run calendar_cron_task again. On window 1 reload the calendar and make all event names have been updated to the correct title. On window 2 click Get these logs button again. Make sure a Calendar event updated event has been logged for each event (should be 75 events in total). Run calendar_cron_task again. Let's mark that subscription to be updated by changing the pollinterval value, for this run the SQL command: UPDATE mdl_event_subscriptions SET pollinterval = 1 WHERE id = THENUMBERYOUMAKENOTE; Run calendar_cron_task again. On window 2 , click Get these logs . Make sure no new Calendar event updated has been logged. Make sure only a single Calendar subscription updated event has been logged.
    • Affected Branches:
      MOODLE_30_STABLE, MOODLE_31_STABLE, MOODLE_33_STABLE, MOODLE_35_STABLE, MOODLE_36_STABLE, MOODLE_37_STABLE
    • Fixed Branches:
      MOODLE_36_STABLE, MOODLE_37_STABLE
    • Pull from Repository:
    • Pull 3.6 Branch:
    • Pull 3.7 Branch:
    • Pull Master Branch:
      MDL-56223-master
    • Story Points:
      3
    • Sprint:
      Internationals - 3.8 Sprint 2, Internationals - 3.8 Sprint 3, Internationals - 3.8 Sprint 4, Internationals - 3.8 Sprint 5, Internationals - 3.8 Sprint 6

      Description

      Moodle v3.0.3+ (Build: 20160324)

      We were seeing some CPU spikes and overloaded php-fpm threads which seemed to be affecting one of our nodes making it unresponsive (we have 3).

      Further research looks like it may be related to random calendar events in the logs. They are intermittent with approx 1071 transactions per second occurring intermittently (looks like about every hour and 15 mins).

      They are always related to the same user with Calendar Event Updated/Created

      User full name: Administrator
      Affected user: name of one specific user
      Event context: User: same user as above
      Component: system
      Event name: Calendar event updated/created
      Origin: cli

      Is this related to https://tracker.moodle.org/browse/MDL-46539 ?

        Attachments

          Issue Links

            Activity

              People

              • Votes:
                21 Vote for this issue
                Watchers:
                33 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:
                  Fix Release Date:
                  9/Sep/19

                  Time Tracking

                  Estimated:
                  Original Estimate - 0 minutes
                  0m
                  Remaining:
                  Remaining Estimate - 0 minutes
                  0m
                  Logged:
                  Time Spent - 1 week, 3 days, 5 hours, 6 minutes
                  1w 3d 5h 6m