xAPI-vle
Errors found in cron log
Description
- Errors observed in the cron log when the task runs:
Dec 5 12:29:38 hostname sitename: Execute scheduled task: Emit records to LRS
Dec 5 12:29:38 hostname sitename: ... started 12:29:38. Current memory use 87.1MB.
Dec 5 12:29:38 hostname sitename: PHP Notice: Undefined offset: 1 in /var/www/sitepath/admin/tool/log/store/xapi/src/transformer/events/mod_feedback/item_answered/multichoice.php on line 30
Dec 5 12:29:38 hostname sitename: PHP Notice: Undefined offset: 2 in /var/www/sitepath/admin/tool/log/store/xapi/src/transformer/events/mod_feedback/item_answered/multichoice.php on line 30
Dec 5 12:29:38 hostname sitename: PHP Notice: Undefined offset: 1 in /var/www/sitepath/admin/tool/log/store/xapi/src/transformer/events/mod_feedback/item_answered/multichoice.php on line 30
Dec 5 12:29:40 hostname sitename: Events (1027462, 1027464, 1027466, 1027467, 1027468, 1027469, 1027472, 1027474, 1027475, 1027477, 1027480, 1027482, 1027485, 1027486, 1027488, 1027489, 1027490, 1027493, 1027494, 1027497, 1027499, 1027504, 1027505, 1027511, 1027513, 1027514, 1027517, 1027518, 1027521, 1027523, 1027524, 1027525, 1027526, 1027527, 1027529, 1027530, 1027531, 1027536, 1027538, 1027542, 1027543, 1027544, 1027546, 1027547, 1027548, 1027549, 1027551, 1027552, 1027554, 1027555, 1027556, 1027557, 1027559, 1027460, 1027461, 1027463, 1027465, 1027470, 1027471, 1027473, 1027476, 1027478, 1027479, 1027481, 1027483, 1027484, 1027487, 1027491, 1027492, 1027495, 1027496, 1027498, 1027500, 1027501, 1027502, 1027503, 1027506, 1027507, 1027508, 1027509, 1027510, 1027512, 1027515, 1027516, 1027519, 1027520, 1027522, 1027528, 1027532, 1027533, 1027534, 1027535, 1027537, 1027539, 1027540, 1027541, 1027545, 1027550, 1027553, 1027558) have been successfully sent to LRS.
Dec 5 12:29:40 hostname sitename: ... used 327 dbqueries
Dec 5 12:29:40 hostname sitename: ... used 1.9848759174347 seconds
Dec 5 12:29:40 hostname sitename: Scheduled task complete: Emit records to LRS
Paths and hostnames/sitenames have been anonymised but these should not be relevant.
Version
- 3.17.0
Steps to reproduce the bug
- Run the plugin
- Observe log in cron
Expected behaviour
- No errors should be emitted
Actual behaviour
- Errors are logged as above.
Server information
- Postgres on Ubuntu 14.04 LTS
Client information
- OS: n/a
- Browser: n/a
Additional information
- n/a
@peterspicer-catalyst I would guess that this is either:
- A code error (in which case I would expect the error on all feedback multiple choice questions
- The question choices or perhaps even the whole question got removed between when the question was answered and when the cron ran.
Are you continuing to see this error? Do you think scenario 2 could be a realistic possibility?
I would imagine the latter - this is currently pushing through a fairly large archive of historical data (as you can see, log ids into the 1 million plus mark), so I wouldn't be surprised if the question had been removed.
I haven't been studying the logs in any real depth - I've been mostly monitoring how many DB queries + total time taken so that I can hopefully get archived data out to the LRS, and I've not been looking at the logs because for this particular site, the cron log is enormous. (The LRS emit task might only get to run once every 8-10 minutes despite being marked as an every-minute task.)
@peterspicer-catalyst thanks.
I guess in that case the issue is that the plugin should catch that something it expects to be in the database is no longer there and record a clearer error.
If the data is no longer in the database, there's obviously no way to emit that as an xapi statement. That's just one of the hard limitations of the historical import.
Agreed we should definitely have a clearer error. Good to see that our error handling caught that and carried on processing the other events.
Is it possible that this issue is similar to https://github.com/xAPI-vle/moodle-logstore_xapi/issues/317 @caperneoignis?
@ryansmith94 could be, I'll look at the code to see what is happening.
@ryansmith94 Looks like the handler for feedback maybe having the same issue as mod_quiz handler where the $event->id is pulling the wrong record.. and we need two lookups to paste the event->id with the actual feedbackitem. Maybe, I haven't put this through a debugger to step through the actual lookup but looks possible since $feedback->value doesn't exist. might be handing it a false or blank string maybe?
https://github.com/xAPI-vle/moodle-logstore_xapi/blob/v3.17.0/src/transformer/events/mod_feedback/response_submitted/handler.php line 26 looks similar to the way mod_quiz was doing it before I spotted the bad lookup using $event->id.