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

[smangancap]

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]

I'm not sure what you would ever get a null value for recording type. Here's the critical line of code:

moodle-mod_zoom/classes/webservice.php

Line 1073 in 6598de0

$recordinginfo->recordingtype = $recording->recording_type;

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]

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]

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:

• line 293 of /lib/dml/moodle_read_slave_trait.php: call to moodle_database->query_end()
• line 341 of /lib/dml/pgsql_native_moodle_database.php: call to pgsql_native_moodle_database->read_slave_query_end()
• line 1132 of /lib/dml/pgsql_native_moodle_database.php: call to pgsql_native_moodle_database->query_end()
• line 1180 of /lib/dml/pgsql_native_moodle_database.php: call to pgsql_native_moodle_database->insert_record_raw()
• line 153 of /mod/zoom/classes/task/get_meeting_recordings.php: call to pgsql_native_moodle_database->insert_record()
• line 263 of /lib/cronlib.php: call to mod_zoom\task\get_meeting_recordings->execute()
• line 120 of /lib/cronlib.php: call to cron_run_inner_scheduled_task()
• line 73 of /lib/cronlib.php: call to cron_run_scheduled_tasks()
• line 178 of /admin/cli/cron.php: call to cron_run()

[jrchamp]

Hi @smangancap, thanks for your quick response. We have a potential fix: 03c7c3b. 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]

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]

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]

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

[smangancap]

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]

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:

moodle-mod_zoom/classes/webservice.php

Line 1123 in 8dc452f

$recordinginfo->recordingtype = $recording->recording_type;

[smangancap]

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:

• line 293 of /lib/dml/moodle_read_slave_trait.php: call to moodle_database->query_end()
• line 341 of /lib/dml/pgsql_native_moodle_database.php: call to pgsql_native_moodle_database->read_slave_query_end()
• line 1132 of /lib/dml/pgsql_native_moodle_database.php: call to pgsql_native_moodle_database->query_end()
• line 1180 of /lib/dml/pgsql_native_moodle_database.php: call to pgsql_native_moodle_database->insert_record_raw()
• line 153 of /mod/zoom/classes/task/get_meeting_recordings.php: call to pgsql_native_moodle_database->insert_record()
• line 263 of /lib/cronlib.php: call to mod_zoom\task\get_meeting_recordings->execute()
• line 167 of /admin/cli/scheduled_task.php: call to cron_run_inner_scheduled_task()

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

[jrchamp]

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]

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]

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