search

ncstate-delta / moodle-mod_zoom

Moodle plugin for Zoom meeting
https://moodle.org/plugins/mod_zoom
61 stars 107 forks source link

Task Fail: Get meeting recordings from Zoom: null value in column "recordingtype" violates not-null constraint #619

Closed smangancap closed 1 month ago

smangancap commented 1 month ago

Moodle 4.1.12 (Build: 20240812) Zoom Meeting v5.2.32024072500

Get meeting recordings from Zoom (mod_zoom\task\get_meeting_recordings) fails with:

Error: null value in column "recordingtype" violates not-null constraint

This is halting all other meeting recording retrievals.

Since the last update had to do with a modification to recordingtype I am wondering if there was a regression. I haven't been able to find any other bug reports or discussions around this specific error yet.

Update: I was able to locate the Zoom meeting activity in Moodle and I can't find anything out of the norm in the settings. It is set up to be a recurring meeting. There have been 4 sessions so far with this particular ID and the previous recordingtype values were set to chat_file.

Also, a breakout room was created but no participants added. I tried to delete the breakout room just for the fun of it but could not. No error, the room just wouldn't delete after I saved the activity. I tried same in a different activity. Checked system logs, no nginx errors. Unsure if any of this could be related to the original problem of the task fail, but thinking more info the better.

Hoping that additional information helps.

jrchamp commented 1 month ago

I'm not sure what you would ever get a null value for recording type. Here's the critical line of code: https://github.com/ncstate-delta/moodle-mod_zoom/blob/6598de0f6258b1261759a732013a10d5baf58e97/classes/webservice.php#L1073

Zoom's Get meeting recordings API suggests that the recording_type value will always be a string from the list they provide. If you are able to debug this somewhere safely, if (empty($recording->recording_type)) { var_dump($recording); }

As an alternative, the crtiical line of code could be modified to default to a non-null value $recordinginfo->recordingtype = $recording->recording_type ?? 'null';. This will set the value to the string "null" so that the data can be loaded even if it does not have a value.

If you get more information about the problematic data element, we would be very interested to know if this is a valid data element or if there is an issue in Zoom's API.

smangancap commented 1 month ago

Hello, thank you so much for getting back. The problem seems to have auto-magically resolved itself this week and I can't explain what change could have occurred to resolve it. There was no back-end DB updates or configuration changes made.

smangancap commented 1 month ago

I spoke too soon. The errors stopped and the job ran consecutively for a number of days and in checking our sys logs again, we appear to have a new one. Same error, different moodle course, different recording.

When we retrieve the actual recording on Zoom.us the type is: Shared screen with speaker view

Here is the full stack trace:

Scheduled task failed: Get meeting recordings from Zoom (mod_zoom\task\get_meeting_recordings),Error writing to database Debug info: ERROR: null value in column "recordingtype" violates not-null constraint DETAIL: Failing row contains (1789, 2863, y+nE7I7aRzC7nlusgiB/qg==, 082917b0-c201-4a0b-a83e-1861543c1516, Zoom Lecture - Sep 18, 2023 - 8:30 to 11:30 am, https://capu.zoom.us/rec/play/xxxxxxxxxxx..., xxxxxx, null, 1726673330, 1, 1726751581, 1726751581). INSERT INTO mdl_zoom_meeting_recordings (zoomid,meetinguuid,zoomrecordingid,name,externalurl,passcode,recordingtype,recordingstart,showrecording,timecreated,timemodified) VALUES($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11) RETURNING id [array ( 'zoomid' => '2863', 'meetinguuid' => 'y+nE7I7aRzC7nlusgiB/qg==', 'zoomrecordingid' => '082917b0-c201-4a0b-a83e-1861543c1516', 'name' => 'Zoom Lecture - Sep 18, 2023 - 8:30 to 11:30 am', 'externalurl' => 'https://capu.zoom.us/rec/play/xxxxxxxxxx', 'passcode' => 'xxxxxxxx', 'recordingtype' => NULL, 'recordingstart' => 1726673330, 'showrecording' => '1', 'timecreated' => 1726751581, 'timemodified' => 1726751581, )] Backtrace:

jrchamp commented 1 month ago

Hi @smangancap, thanks for your quick response. We have a potential fix: https://github.com/ncstate-delta/moodle-mod_zoom/pull/620/commits/03c7c3b5b072f6baee2d0bb15d676157963e1c01. If the error is still occurring and you can add the code that will show the structure of the recording object, it may help explain if Zoom's API is behaving differently these days or perhaps has a bug.

if (empty($recording->recording_type)) {
    var_dump($recording);
}
smangancap commented 1 month ago

I can see how this would be helpful for you to debug, but unfortunately, since we are hosted I don't have permissions to modify the code.

smangancap commented 1 month ago

The last modification to the Zoom plugin v5.2.3 indicates:

Regression: recordingtype column was too small for some type strings #605 (thanks @samwitzig, @acquaalta) Introduced in v5.2.1 when fixing recording type language strings.

Could this have anything to do with it?

It appears as though the type is: Shared screen with speaker view as per my post above.

Update: I checked the details of the last updates and confirmed that characters were increased to 50 for that field in our installation. Odd that this is the same recordingtype it is hiccuping on though.

recordingtype | character varying(50) | | not null | ''::character varying

smangancap commented 1 month ago

Another update - just heard back from our vendor and he is willing to update the code to debug for us.

smangancap commented 1 month ago 
if (empty($recording->recording_type)) {
    var_dump($recording);
}

Can you please confirm which file and this entry goes? Would it be the file that cron is tripping up on or the webservice file? Sorry, I'm not a developer :)

/mod/zoom/classes/webservice.php or /mod/zoom/classes/task/get_meeting_recordings.php

Also, where specifically we should put it. Thank you.

jrchamp commented 1 month ago

In webservice.php, within the get_user_recordings() function. It may be best for that debug code to be immediately before the related line of code: https://github.com/ncstate-delta/moodle-mod_zoom/blob/8dc452f28c3c60c99a1666b825df0837470f8c46/classes/webservice.php#L1123

smangancap commented 1 month ago

I couldn't recreate the problem on our development instance so we just updated our production server.

Here's the output of the cron job log after inserting that code. I also upped debugging to developer temporarily and checked the server logs and nothing specific to this was logged there.

The error still exists for a few of our courses now and is still halting all other recordings from being returned back to moodle. I will continue to work on trying to find some commonality in the zoom meeting configuration for the courses that are returning the error.

Get meeting recordings from Zoom Execute scheduled task: Get meeting recordings from Zoom (mod_zoom\task\get_meeting_recordings) ... started 10:14:23. Current memory use 16.5 MB. Finding meeting recordings for this account... Recording id: 57ba7966-d337-48bf-8c5a-a77b58505d64 exists...skipping Recording id: 8a5cf846-b84d-41a8-ba1d-244feb34821f exists...skipping Recording id: 9db2e398-f82d-4964-997a-e121d5e0a199 exists...skipping Recording id: ca36843f-4125-4e86-b548-58bc7ab8e8af exists...skipping Recording id: 0873ae4a-4f71-4f06-ad6f-6ffd50da41b5 exists...skipping Recording id: d650ae42-000b-4651-8815-fb701f387f2a exists...skipping Meeting id: 64329308632 does not exist...skipping Meeting id: 64329308632 does not exist...skipping object(stdClass)#648 (10) { ["id"]=> string(36) "a4cec3a2-fa86-4183-9056-2a867a8338ca" ["meeting_id"]=> string(24) "LDTuMMSPRUW8B3Qq9a4sZg==" ["recording_start"]=> string(20) "2024-09-24T01:16:17Z" ["recording_end"]=> string(20) "2024-09-24T04:21:58Z" ["file_type"]=> string(4) "CHAT" ["file_extension"]=> string(3) "TXT" ["file_size"]=> int(1156) ["play_url"]=> string(127) "https://capu.zoom.us/rec/play/Fm9AY697Dl436dhSXrNSnTLRY7WjpPj9haWM7uBdeTCimsRRo91dBxEP_C7HFZexQ4LeaFhDKVOXQQ8H.Ef4ZISFzm8vdt9hd" ["download_url"]=> string(131) "https://capu.zoom.us/rec/download/Fm9AY697Dl436dhSXrNSnTLRY7WjpPj9haWM7uBdeTCimsRRo91dBxEP_C7HFZexQ4LeaFhDKVOXQQ8H.Ef4ZISFzm8vdt9hd" ["status"]=> string(9) "completed" } Recording id: 22f476d1-438c-474d-af4a-aea6ef82f0ab exists...skipping Recording id: 81b07e9b-4f50-4033-aad9-720a210fb6d2 exists...skipping ... used 3 dbqueries ... used 7.2225430011749 seconds Scheduled task failed: Get meeting recordings from Zoom (mod_zoom\task\get_meeting_recordings),Error writing to database Debug info: ERROR: null value in column "recordingtype" violates not-null constraint DETAIL: Failing row contains (1856, 2748, LDTuMMSPRUW8B3Qq9a4sZg==, a4cec3a2-fa86-4183-9056-2a867a8338ca, ZOOM Class link passcode is 733671, https://capu.zoom.us/rec/play/Fm9AY697Dl436dhSXrNSnTLRY7WjpPj9ha..., tr5$9!Cj, null, 1727140577, 1, 1727198063, 1727198063). INSERT INTO mdl_zoom_meeting_recordings (zoomid,meetinguuid,zoomrecordingid,name,externalurl,passcode,recordingtype,recordingstart,showrecording,timecreated,timemodified) VALUES($1,$2,$3,$4,$5,$6,$7,$8,$9,$10,$11) RETURNING id [array ( 'zoomid' => '2748', 'meetinguuid' => 'LDTuMMSPRUW8B3Qq9a4sZg==', 'zoomrecordingid' => 'a4cec3a2-fa86-4183-9056-2a867a8338ca', 'name' => 'ZOOM Class link passcode is 733671', 'externalurl' => 'https://capu.zoom.us/rec/play/Fm9AY697Dl436dhSXrNSnTLRY7WjpPj9haWM7uBdeTCimsRRo91dBxEP_C7HFZexQ4LeaFhDKVOXQQ8H.Ef4ZISFzm8vdt9hd', 'passcode' => 'tr5$9!Cj', 'recordingtype' => NULL, 'recordingstart' => 1727140577, 'showrecording' => '1', 'timecreated' => 1727198063, 'timemodified' => 1727198063, )] Backtrace:

Just as a reminder we are on: Moodle 4.1.12 (Build: 20240812) Zoom Meeting v5.2.32024072500

jrchamp commented 1 month ago

Thank you @smangancap! It seems that recording_type is not always being set even though the Zoom API documentation implies that it would always to be set. That seems like a bug in Zoom's API, but also something that we should have a fallback in place for.

If you are able, please apply the fix from #620. This should allow the data to at least load (and display the type as "null"). When/if the recording_type data becomes available from Zoom, the displayed string should automatically correct itself to match Zoom. I'll try to report the issue to Zoom's API team and hopefully it will stop happening.

smangancap commented 1 month ago

Thank you @jrchamp. To confirm this fix won't be pushed out into an actual release? Our host has a policy to not update core code so I don't think we will be able to apply the fix manually. The only reason they allowed the debugging code is that it wouldn't affect anything negatively on next upgrade whereas a change like this will unless continued to be patched each time.

Update: disregard my comment above - we were able to apply the code change. Thank you very much for your quick response to help resolve this.

jrchamp commented 3 weeks ago

A few days ago, we were able to release this fix as part of v5.2.4. Sorry for the delay. ❤️