[OJS-3.4.0-4] Statistic problem

Windows PowerShell:

Edit:

I go down the path one by one and apply the patches :slightly_smiling_face:

Ha, it seems it is not so easy to apply a patch on windows :frowning:
After googling, it seems people recommend using gnuwin32, cygwin, or git for windows…

Hi @shantanusingh,

I have just sent you the patched package…

Let me know when this all is fine and you are ready to start to re-process the log files. Then I will again write you what steps you should do…

1 Like

Hi @Bozana I have applied the suggested ([OJS-3.4.0-4] Statistic problem - #18 by bozana) patch and I hope it will work. Please see the message for more and guide me.

If this is ok we will be ready to process the log files again.

Hi @shantanusingh,

Yes, that looks good.
Could you please double check if you the column ip in those usage stats temporary tables is now VARCHAR(64), and that there is an index (load_id, context_id and ip) in these tables:

usage_stats_total_temporary_records, 
usage_stats_unique_item_investigations_temporary_records,
usage_stats_unique_item_requests_temporary_records

Then we can already see what is happening with the next scheduled task that will try to process your current log file.
Can you please go to the DB table scheduled_tasks, find there the entry with class_name = 'APP\tasks\UsageStatsLoader' and see what is in the column last_run for that entry? You can execute:
select * from scheduled_tasks where class_name = 'APP\tasks\UsageStatsLoader'

This scheduled task should run every day – on the first request made after 24 hours after the last run. And it should process the log file from the day before. So after that scheduled task has run tomorrow (i.e. after your patch), we can see what happened with the log file from today…

From another user that had the same problem I have heard that the job still takes some time, but I think your max_execution_time = 600 (seconds) should be enough for the job.

So lets first see if a new job CompileUsageStatsFromTemporaryRecords (after your patch) runs successfully…

Hi @Bozana I think it is working and the stats are showing. I have highlighted (Bold) your points, please see.

mysql> DESCRIBE usage_stats_total_temporary_records;
±--------------------------±----------------±-----±----±--------±---------------+
| Field | Type | Null | Key | Default | Extra |
±--------------------------±----------------±-----±----±--------±---------------+
| usage_stats_temp_total_id | bigint unsigned | NO | PRI | NULL | auto_increment |
| date | datetime | NO | | NULL | |
| ip | varchar(64) | NO | | NULL | |
| user_agent | varchar(255) | NO | | NULL | |
| line_number | bigint | NO | | NULL | |
| canonical_url | varchar(255) | NO | | NULL | |
| issue_id | bigint | YES | MUL | NULL | |
| issue_galley_id | bigint | YES | MUL | NULL | |
| context_id | bigint | NO | MUL | NULL | |
| submission_id | bigint | YES | MUL | NULL | |
| representation_id | bigint | YES | MUL | NULL | |
| submission_file_id | bigint unsigned | YES | MUL | NULL | |
| assoc_type | bigint | NO | | NULL | |
| file_type | smallint | YES | | NULL | |
| country | varchar(2) | NO | | | |
| region | varchar(3) | NO | | | |
| city | varchar(255) | NO | | | |
| load_id | varchar(50) | NO | MUL | NULL | |
±--------------------------±----------------±-----±----±--------±---------------+
18 rows in set (0.03 sec)

mysql> DESCRIBE usage_stats_unique_item_investigations_temporary_records;
±--------------------------------±----------------±-----±----±--------±---------------+
| Field | Type | Null | Key | Default | Extra |
±--------------------------------±----------------±-----±----±--------±---------------+
| usage_stats_temp_unique_item_id | bigint unsigned | NO | PRI | NULL | auto_increment |
| date | datetime | NO | | NULL | |
| ip | varchar(64) | NO | | NULL | |
| user_agent | varchar(255) | NO | | NULL | |
| line_number | bigint | NO | | NULL | |
| context_id | bigint | NO | MUL | NULL | |
| submission_id | bigint | NO | MUL | NULL | |
| representation_id | bigint | YES | MUL | NULL | |
| submission_file_id | bigint unsigned | YES | MUL | NULL | |
| assoc_type | bigint | NO | | NULL | |
| file_type | smallint | YES | | NULL | |
| country | varchar(2) | NO | | | |
| region | varchar(3) | NO | | | |
| city | varchar(255) | NO | | | |
| load_id | varchar(50) | NO | MUL | NULL | |
±--------------------------------±----------------±-----±----±--------±---------------+
15 rows in set (0.00 sec)

mysql> DESCRIBE usage_stats_unique_item_requests_temporary_records;
±-------------------------±----------------±-----±----±--------±---------------+
| Field | Type | Null | Key | Default | Extra |
±-------------------------±----------------±-----±----±--------±---------------+
| usage_stats_temp_item_id | bigint unsigned | NO | PRI | NULL | auto_increment |
| date | datetime | NO | | NULL | |
| ip | varchar(64) | NO | | NULL | |
| user_agent | varchar(255) | NO | | NULL | |
| line_number | bigint | NO | | NULL | |
| context_id | bigint | NO | MUL | NULL | |
| submission_id | bigint | NO | MUL | NULL | |
| representation_id | bigint | YES | MUL | NULL | |
| submission_file_id | bigint unsigned | YES | MUL | NULL | |
| assoc_type | bigint | NO | | NULL | |
| file_type | smallint | YES | | NULL | |
| country | varchar(2) | NO | | | |
| region | varchar(3) | NO | | | |
| city | varchar(255) | NO | | | |
| load_id | varchar(50) | NO | MUL | NULL | |
±-------------------------±----------------±-----±----±--------±---------------+
15 rows in set (0.01 sec)

mysql> select * from scheduled_tasks where class_name = ‘APP\tasks\UsageStatsLoader’;
Empty set (0.00 sec)

mysql> select * from scheduled_tasks;
±------------------±--------------------------------------------------------------------------------±--------------------+
| scheduled_task_id | class_name | last_run |
±------------------±--------------------------------------------------------------------------------±--------------------+
| 1 | APP\plugins\importexport\doaj\DOAJInfoSender | 2024-01-26 10:30:39 |
| 2 | APP\tasks\SubscriptionExpiryReminder | 2024-01-01 00:00:07 |
| 3 | classes.tasks.ReviewReminder | 2022-04-18 13:01:37 |
| 4 | PKP\task\ReviewReminder | 2024-01-26 03:02:47 |
| 5 | PKP\task\StatisticsReport | 2024-01-01 00:00:05 |
| 6 | plugins.generic.alm.ArticleInfoSender | 2019-08-08 16:26:19 |
| 7 | plugins.generic.crossrefReferenceLinking.CrossrefReferenceLinkingInfoSender | 2023-11-30 17:14:23 |
| 12 | PKP\task\DepositDois | 2024-01-26 11:51:18 |
| 13 | PKP\task\RemoveUnvalidatedExpiredUsers | 2024-01-01 11:49:31 |
| 14 | PKP\task\EditorialReminders | 2024-01-01 11:49:31 |
| 15 | PKP\task\UpdateIPGeoDB | 2024-01-10 00:00:02 |
| 16 | APP\tasks\UsageStatsLoader | 2024-01-26 11:51:25 |
| 17 | PKP\task\ProcessQueueJobs | 2024-01-26 11:51:37 |
| 18 | PKP\task\RemoveFailedJobs | 2024-01-01 11:49:44 |
| 19 | APP\tasks\OpenAccessNotification | 2024-01-26 11:51:37 |
| 20 | APP\plugins\generic\crossrefReferenceLinking\CrossrefReferenceLinkingInfoSender | 2023-12-11 16:55:08 |
| 21 | APP\plugins\generic\pln\classes\tasks\Depositor | 2024-01-26 10:03:50 |
±------------------±--------------------------------------------------------------------------------±--------------------+
17 rows in set (0.00 sec)

Now I want to process the previous failed log files again.

Hi @shantanusingh

Great! :tada:
For log file re-processing it is good that you keep daily stats. This way you can re-process file by file – and not all file for a month at once. It is important to currently re-process one by one file, because else it would probably lead to timeout again.
(If we would re-process several files, the temporary tables would be filled with the next file information before the jobs from the previous file have finished. I am working on the solution for this, but it will take a few days.)

You should probably re-process all files from the day when you have installed the 3.4 release till yesterday. You said you installed it on the December 1st, so you can start with that log file and stop after you have re-processed the file from January 24th.

Here what you would need to do:
The archived log files are in the folder usageStats/archive/.
Double check what was the first log file created with the release 3.4 – when you have installed the 3.4 release – it will be the first log file that contains rows in JSON format. Maybe it is usage_events_20231201.log?
Double check that temporary usage stats DB tables are empty and there are no failed statistics jobs.

Then:

  1. Copy that first file from the folder usageStats/archive/ into the folder usageStats/usageEventLogs/.
  2. Remove the row that contains APP\tasks\UsageStatsLoader from the DB table scheduled_tasks, e.g. by running:
    DELETE FROM scheduled_tasks where class_name = ‘APP\tasks\UsageStatsLoader’;
    This will allow the scheduled task to run with the next request (instead of next day).
    (2a. The next request of your journal’s page will run the scheduled task.)
  3. When the scheduled task is run you will see it again in the DB table scheduled_tasks, you will see that your log file is again in the archive folder, and you will see two new jobs in the DB table jobs. Double check that.
    (3a. The next request (or two) of your journal’s page will run one or both jobs.)
  4. Now you should see that the two jobs from the DB table jobs are not there any more. Double check that they have not failed (that they are not in the DB table failed_jobs).
  5. Double check that statistics for that day exists – either via the UI or e.g. in the DB table metrics_context or metrics_submission.

Do the steps from 1-5 for each file in December and till January 24th.

Let me know how it goes…

Best,
Bozana

One more thing: You said that a few log files are in the folder reject/. Lets ignore them for now. Once you have finished the re-processing of the other log files, we can take a look at them.

Hi @bozana
Thanks for the solution and guidance. I will try to update the log files and update you when the process is done. :slightly_smiling_face: :grinning:

I have checked the folders, today 2 log files were processed and one (23 Jan 2024) is in the processing stage.

The log file is as follows:- usage_events_20240125.log.

There are 7 log files available in the reject folder.

Hi @bozana

I have processed January 2024 log files and it is taking about 7 minutes to complete the task for one log file (40MB). I have noticed that if I put in a two-day log file and try to process one log file gets stuck due to the wait time. So I have tried executing the log files one by one.

Some failure logs are still in the reject/ folder of January 2024, I will try if you guide me.

I have tried to process the December 2023 log file, but it is saying that the log file Skipped log file usage_events_20231204.log because statistics from that month have already been calculated. To recalculate statistics for a previous month, you must restore all of that month's log files and use the CLI tool to reprocess statistics. So I think I should leave it, it might get stuck or I might get into trouble.

Hi @shantanusingh,

I have tried to process the December 2023 log file, but it is saying that the log file Skipped log file usage_events_20231204.log because statistics from that month have already been calculated. To recalculate statistics for a previous month, you must restore all of that month's log files and use the CLI tool to reprocess statistics. So I think I should leave it, it might get stuck or I might get into trouble.

So you do not keep the daily stats (see in admin statistics settings)?
If so, yes, better to leave it for now. I am working on a fix for that too, but it will take a few days + code review…

And regarding the rejected files:
Lets take one of them and copy it to the stage/ folder. Then do all the steps from the above, as for other log files from January that you have reprocessed.
If it lands in the reject/ folder again, see the current scheduled task log file – This is a file in the scheduledTasks/ folder in your files folder, with the name Usagestatisticsfileloadertask-…-YYYYMMDD.log. The reason why the file failed should be logged in that file.
Let me know then…

Best,
Bozana

Hi @bozana

As per your suggestion, I have run the reject/ folder of January 2024 and it was completed successfully.
Thanks for the guidance. :grinning:

Hi, @Bozana The statistics for the last date of the month are not processing.

I noticed that if we set Monthly or Daily Statistics to Only track monthly statistics and process the last date of the month’s usage log file then it shows an error during log file processing. [Error] Skipped log file usage_events_20240131.log because statistics from that month have already been calculated. To recalculate statistics for a previous month, you must restore all of that month's log files and use the CLI tool to reprocess statistics.

If we set Monthly or Daily Statistics to Track daily and monthly statistics and run a manual month-end date usage state then usage_events_20240131.log is archived and it shows an error.

[01-Feb-2024 10:12:52 Asia/Kolkata] PDOException: SQLSTATE[23000]: Integrity constraint violation: 1452 Cannot add or update a child row: a foreign key constraint fails (`ojs4`.`metrics_submission`, CONSTRAINT `metrics_submission_representation_id_foreign` FOREIGN KEY (`representation_id`) REFERENCES `publication_galleys` (`galley_id`) ON DELETE CASCADE) in /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php:570
Stack trace:
#0 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(570): PDOStatement->execute()
#1 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(753): Illuminate\Database\Connection->Illuminate\Database\{closure}()
#2 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(720): Illuminate\Database\Connection->runQueryCallback()
#3 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(577): Illuminate\Database\Connection->run()
#4 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Query/Builder.php(3340): Illuminate\Database\Connection->affectingStatement()
#5 /ojs/lib/pkp/classes/statistics/PKPTemporaryTotalsDAO.php(163): Illuminate\Database\Query\Builder->insertUsing()
#6 /ojs/jobs/statistics/CompileUsageStatsFromTemporaryRecords.php(103): PKP\statistics\PKPTemporaryTotalsDAO->compileSubmissionMetrics()
#7 /ojs/jobs/statistics/CompileUsageStatsFromTemporaryRecords.php(55): APP\jobs\statistics\CompileUsageStatsFromTemporaryRecords->compileMetrics()
#8 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): APP\jobs\statistics\CompileUsageStatsFromTemporaryRecords->handle()
#9 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
#10 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\Container\Util::unwrapIfClosure()
#11 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(37): Illuminate\Container\BoundMethod::callBoundMethod()
#12 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/Container.php(661): Illuminate\Container\BoundMethod::call()
#13 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(128): Illuminate\Container\Container->call()
#14 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\Bus\Dispatcher->Illuminate\Bus\{closure}()
#15 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}()
#16 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(132): Illuminate\Pipeline\Pipeline->then()
#17 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(124): Illuminate\Bus\Dispatcher->dispatchNow()
#18 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\Queue\CallQueuedHandler->Illuminate\Queue\{closure}()
#19 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}()
#20 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(126): Illuminate\Pipeline\Pipeline->then()
#21 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(70): Illuminate\Queue\CallQueuedHandler->dispatchThroughMiddleware()
#22 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(98): Illuminate\Queue\CallQueuedHandler->call()
#23 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(425): Illuminate\Queue\Jobs\Job->fire()
#24 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(375): Illuminate\Queue\Worker->process()
#25 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(326): Illuminate\Queue\Worker->runJob()
#26 /ojs/lib/pkp/classes/core/PKPQueueProvider.php(104): Illuminate\Queue\Worker->runNextJob()
#27 /ojs/lib/pkp/classes/queue/JobRunner.php(220): PKP\core\PKPQueueProvider->runJobInQueue()
#28 /ojs/lib/pkp/classes/core/PKPQueueProvider.php(128): PKP\queue\JobRunner->processJobs()
#29 [internal function]: PKP\core\PKPQueueProvider->PKP\core\{closure}()
#30 {main}

Next Illuminate\Database\QueryException: SQLSTATE[23000]: Integrity constraint violation: 1452 Cannot add or update a child row: a foreign key constraint fails (`ojs4`.`metrics_submission`, CONSTRAINT `metrics_submission_representation_id_foreign` FOREIGN KEY (`representation_id`) REFERENCES `publication_galleys` (`galley_id`) ON DELETE CASCADE) (SQL: insert into `metrics_submission` (`load_id`, `context_id`, `submission_id`, `representation_id`, `submission_file_id`, `file_type`, `assoc_type`, `date`, `metric`) select load_id, context_id, submission_id, representation_id, submission_file_id, file_type, assoc_type, DATE(date) as date, count(*) as metric from `usage_stats_total_temporary_records` where `load_id` = usage_events_20240131.log and `assoc_type` = 515 group by load_id, context_id, submission_id, representation_id, submission_file_id, file_type, assoc_type, DATE(date)) in /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php:760
Stack trace:
#0 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(720): Illuminate\Database\Connection->runQueryCallback()
#1 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(577): Illuminate\Database\Connection->run()
#2 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Query/Builder.php(3340): Illuminate\Database\Connection->affectingStatement()
#3 /ojs/lib/pkp/classes/statistics/PKPTemporaryTotalsDAO.php(163): Illuminate\Database\Query\Builder->insertUsing()
#4 /ojs/jobs/statistics/CompileUsageStatsFromTemporaryRecords.php(103): PKP\statistics\PKPTemporaryTotalsDAO->compileSubmissionMetrics()
#5 /ojs/jobs/statistics/CompileUsageStatsFromTemporaryRecords.php(55): APP\jobs\statistics\CompileUsageStatsFromTemporaryRecords->compileMetrics()
#6 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): APP\jobs\statistics\CompileUsageStatsFromTemporaryRecords->handle()
#7 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
#8 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\Container\Util::unwrapIfClosure()
#9 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(37): Illuminate\Container\BoundMethod::callBoundMethod()
#10 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/Container.php(661): Illuminate\Container\BoundMethod::call()
#11 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(128): Illuminate\Container\Container->call()
#12 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\Bus\Dispatcher->Illuminate\Bus\{closure}()
#13 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}()
#14 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(132): Illuminate\Pipeline\Pipeline->then()
#15 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(124): Illuminate\Bus\Dispatcher->dispatchNow()
#16 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\Queue\CallQueuedHandler->Illuminate\Queue\{closure}()
#17 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}()
#18 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(126): Illuminate\Pipeline\Pipeline->then()
#19 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(70): Illuminate\Queue\CallQueuedHandler->dispatchThroughMiddleware()
#20 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(98): Illuminate\Queue\CallQueuedHandler->call()
#21 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(425): Illuminate\Queue\Jobs\Job->fire()
#22 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(375): Illuminate\Queue\Worker->process()
#23 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(326): Illuminate\Queue\Worker->runJob()
#24 /ojs/lib/pkp/classes/core/PKPQueueProvider.php(104): Illuminate\Queue\Worker->runNextJob()
#25 /ojs/lib/pkp/classes/queue/JobRunner.php(220): PKP\core\PKPQueueProvider->runJobInQueue()
#26 /ojs/lib/pkp/classes/core/PKPQueueProvider.php(128): PKP\queue\JobRunner->processJobs()
#27 [internal function]: PKP\core\PKPQueueProvider->PKP\core\{closure}()
#28 {main}
[01-Feb-2024 10:12:52 Asia/Kolkata] #0 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(720): Illuminate\Database\Connection->runQueryCallback()
#1 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(577): Illuminate\Database\Connection->run()
#2 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Query/Builder.php(3340): Illuminate\Database\Connection->affectingStatement()
#3 /ojs/lib/pkp/classes/statistics/PKPTemporaryTotalsDAO.php(163): Illuminate\Database\Query\Builder->insertUsing()
#4 /ojs/jobs/statistics/CompileUsageStatsFromTemporaryRecords.php(103): PKP\statistics\PKPTemporaryTotalsDAO->compileSubmissionMetrics()
#5 /ojs/jobs/statistics/CompileUsageStatsFromTemporaryRecords.php(55): APP\jobs\statistics\CompileUsageStatsFromTemporaryRecords->compileMetrics()
#6 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): APP\jobs\statistics\CompileUsageStatsFromTemporaryRecords->handle()
#7 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
#8 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\Container\Util::unwrapIfClosure()
#9 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(37): Illuminate\Container\BoundMethod::callBoundMethod()
#10 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/Container.php(661): Illuminate\Container\BoundMethod::call()
#11 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(128): Illuminate\Container\Container->call()
#12 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\Bus\Dispatcher->Illuminate\Bus\{closure}()
#13 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}()
#14 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(132): Illuminate\Pipeline\Pipeline->then()
#15 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(124): Illuminate\Bus\Dispatcher->dispatchNow()
#16 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\Queue\CallQueuedHandler->Illuminate\Queue\{closure}()
#17 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}()
#18 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(126): Illuminate\Pipeline\Pipeline->then()
#19 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(70): Illuminate\Queue\CallQueuedHandler->dispatchThroughMiddleware()
#20 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(98): Illuminate\Queue\CallQueuedHandler->call()
#21 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(425): Illuminate\Queue\Jobs\Job->fire()
#22 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(375): Illuminate\Queue\Worker->process()
#23 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(326): Illuminate\Queue\Worker->runJob()
#24 /ojs/lib/pkp/classes/core/PKPQueueProvider.php(104): Illuminate\Queue\Worker->runNextJob()
#25 /ojs/lib/pkp/classes/queue/JobRunner.php(220): PKP\core\PKPQueueProvider->runJobInQueue()
#26 /ojs/lib/pkp/classes/core/PKPQueueProvider.php(128): PKP\queue\JobRunner->processJobs()
#27 [internal function]: PKP\core\PKPQueueProvider->PKP\core\{closure}()
#28 {main}

Hi @shantanusingh,

Ah, yes, this – that the log files from the previous month cannot be processed when the option “Only track monthly statistics” has been selected – seems to be a bug. I opened a new issue for that: [OJS-3.4.0-4] Statistic problem - #33 by shantanusingh.

Could you please double check if the daily stats for january are still in your DB tables, e.g. in the DB table metrics_counter_submission_daily.

The other error that you get is a little bit strange: it means that there is a galley ID in the log file that does not exist any more (ans is thus not in the DB table publication_galleys). But such a line (that contains not existing object IDs) from the log file should actually be ignored – the log file line should be inserted into the temporary tables which would fail (because of the same foreign key error) but the log file processing would continue.

Thus, please let me know if you have the entries in your daily metric tables – to be sure – and I will then tell you how to apply the new patch so that that file can be normally processed…

Thanks!
Bozana

Hi @bozana I checked and found the January log file in the metrics_counter_submissions_daily table.

I tried to process the log file after setting Monthly or Daily Statistics to Track daily and monthly statistics and at that time the log file was Archived but the statistics were not generated. This may be the reason for this error occurring.

So you have all dates from January in that DB table?

Yes, I have checked broadly and found a maximum January 2024 log file.

OK, once the tests pass I will merge the fix and let you know where to find the patch…

1 Like

Hi @shantanusingh,

You would need to apply these changes: pkp/pkp-lib#9679 allow processing of the log files from the last month · pkp/pkp-lib@d0862af · GitHub
by applying the patch like this:

  1. go to your OJS folder and then to lib/pkp/ (cd lib/pkp)
  2. from OJS/lib/pkp/ run the following:
    wget -q -O - https://github.com/pkp/pkp-lib/commit/d0862af7bf5b464a20570c732ba21c5d1c581883.diff | patch -p1

Double check that temporary usage stats DB tables are empty, that there are no failed statistics jobs, that there are no other jobs in the DB table jobs.

Then reprocess the file:

  1. Copy that file usage_events_20240131.log into the folder usageStats/usageEventLogs/.
  2. Remove the row that contains APP\tasks\UsageStatsLoader from the DB table scheduled_tasks, e.g. by running:
    DELETE FROM scheduled_tasks where class_name = ‘APP\tasks\UsageStatsLoader’;
    This will allow the scheduled task to run with the next request (instead of next day).
    (2a. The next request of your journal’s page will run the scheduled task.)
  3. When the scheduled task is run you will see it again in the DB table scheduled_tasks, you will see that your log file is again in the archive folder, and you will see two new jobs in the DB table jobs. Double check that.
    (3a. The next request (or two) of your journal’s page will run one or both jobs.)
  4. Now you should see that the two jobs from the DB table jobs are not there any more. Double check that they have not failed (that they are not in the DB table failed_jobs).
  5. Double check that statistics for that day exists – either via the UI or e.g. in the DB table metrics_context or metrics_submission.

Hope that works then…

Best,
Bozana

Hi @bozana I have applied the patch and run the use_events_20240131.log file but still the same error reported.
use_events_20240131.log file is Archived.

[01-Feb-2024 21:01:08 Asia/Kolkata] PDOException: SQLSTATE[23000]: Integrity constraint violation: 1452 Cannot add or update a child row: a foreign key constraint fails (`ojs4`.`metrics_submission`, CONSTRAINT `metrics_submission_representation_id_foreign` FOREIGN KEY (`representation_id`) REFERENCES `publication_galleys` (`galley_id`) ON DELETE CASCADE) in /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php:570
Stack trace:
#0 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(570): PDOStatement->execute()
#1 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(753): Illuminate\Database\Connection->Illuminate\Database\{closure}()
#2 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(720): Illuminate\Database\Connection->runQueryCallback()
#3 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(577): Illuminate\Database\Connection->run()
#4 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Query/Builder.php(3340): Illuminate\Database\Connection->affectingStatement()
#5 /ojs/lib/pkp/classes/statistics/PKPTemporaryTotalsDAO.php(163): Illuminate\Database\Query\Builder->insertUsing()
#6 /ojs/jobs/statistics/CompileUsageStatsFromTemporaryRecords.php(103): PKP\statistics\PKPTemporaryTotalsDAO->compileSubmissionMetrics()
#7 /ojs/jobs/statistics/CompileUsageStatsFromTemporaryRecords.php(55): APP\jobs\statistics\CompileUsageStatsFromTemporaryRecords->compileMetrics()
#8 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): APP\jobs\statistics\CompileUsageStatsFromTemporaryRecords->handle()
#9 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
#10 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\Container\Util::unwrapIfClosure()
#11 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(37): Illuminate\Container\BoundMethod::callBoundMethod()
#12 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/Container.php(661): Illuminate\Container\BoundMethod::call()
#13 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(128): Illuminate\Container\Container->call()
#14 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\Bus\Dispatcher->Illuminate\Bus\{closure}()
#15 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}()
#16 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(132): Illuminate\Pipeline\Pipeline->then()
#17 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(124): Illuminate\Bus\Dispatcher->dispatchNow()
#18 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\Queue\CallQueuedHandler->Illuminate\Queue\{closure}()
#19 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}()
#20 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(126): Illuminate\Pipeline\Pipeline->then()
#21 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(70): Illuminate\Queue\CallQueuedHandler->dispatchThroughMiddleware()
#22 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(98): Illuminate\Queue\CallQueuedHandler->call()
#23 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(425): Illuminate\Queue\Jobs\Job->fire()
#24 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(375): Illuminate\Queue\Worker->process()
#25 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(326): Illuminate\Queue\Worker->runJob()
#26 /ojs/lib/pkp/classes/core/PKPQueueProvider.php(104): Illuminate\Queue\Worker->runNextJob()
#27 /ojs/lib/pkp/classes/queue/JobRunner.php(220): PKP\core\PKPQueueProvider->runJobInQueue()
#28 /ojs/lib/pkp/classes/core/PKPQueueProvider.php(128): PKP\queue\JobRunner->processJobs()
#29 [internal function]: PKP\core\PKPQueueProvider->PKP\core\{closure}()
#30 {main}

Next Illuminate\Database\QueryException: SQLSTATE[23000]: Integrity constraint violation: 1452 Cannot add or update a child row: a foreign key constraint fails (`ojs4`.`metrics_submission`, CONSTRAINT `metrics_submission_representation_id_foreign` FOREIGN KEY (`representation_id`) REFERENCES `publication_galleys` (`galley_id`) ON DELETE CASCADE) (SQL: insert into `metrics_submission` (`load_id`, `context_id`, `submission_id`, `representation_id`, `submission_file_id`, `file_type`, `assoc_type`, `date`, `metric`) select load_id, context_id, submission_id, representation_id, submission_file_id, file_type, assoc_type, DATE(date) as date, count(*) as metric from `usage_stats_total_temporary_records` where `load_id` = usage_events_20240131.log and `assoc_type` = 515 group by load_id, context_id, submission_id, representation_id, submission_file_id, file_type, assoc_type, DATE(date)) in /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php:760
Stack trace:
#0 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(720): Illuminate\Database\Connection->runQueryCallback()
#1 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(577): Illuminate\Database\Connection->run()
#2 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Query/Builder.php(3340): Illuminate\Database\Connection->affectingStatement()
#3 /ojs/lib/pkp/classes/statistics/PKPTemporaryTotalsDAO.php(163): Illuminate\Database\Query\Builder->insertUsing()
#4 /ojs/jobs/statistics/CompileUsageStatsFromTemporaryRecords.php(103): PKP\statistics\PKPTemporaryTotalsDAO->compileSubmissionMetrics()
#5 /ojs/jobs/statistics/CompileUsageStatsFromTemporaryRecords.php(55): APP\jobs\statistics\CompileUsageStatsFromTemporaryRecords->compileMetrics()
#6 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): APP\jobs\statistics\CompileUsageStatsFromTemporaryRecords->handle()
#7 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
#8 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\Container\Util::unwrapIfClosure()
#9 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(37): Illuminate\Container\BoundMethod::callBoundMethod()
#10 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/Container.php(661): Illuminate\Container\BoundMethod::call()
#11 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(128): Illuminate\Container\Container->call()
#12 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\Bus\Dispatcher->Illuminate\Bus\{closure}()
#13 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}()
#14 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(132): Illuminate\Pipeline\Pipeline->then()
#15 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(124): Illuminate\Bus\Dispatcher->dispatchNow()
#16 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\Queue\CallQueuedHandler->Illuminate\Queue\{closure}()
#17 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}()
#18 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(126): Illuminate\Pipeline\Pipeline->then()
#19 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(70): Illuminate\Queue\CallQueuedHandler->dispatchThroughMiddleware()
#20 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(98): Illuminate\Queue\CallQueuedHandler->call()
#21 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(425): Illuminate\Queue\Jobs\Job->fire()
#22 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(375): Illuminate\Queue\Worker->process()
#23 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(326): Illuminate\Queue\Worker->runJob()
#24 /ojs/lib/pkp/classes/core/PKPQueueProvider.php(104): Illuminate\Queue\Worker->runNextJob()
#25 /ojs/lib/pkp/classes/queue/JobRunner.php(220): PKP\core\PKPQueueProvider->runJobInQueue()
#26 /ojs/lib/pkp/classes/core/PKPQueueProvider.php(128): PKP\queue\JobRunner->processJobs()
#27 [internal function]: PKP\core\PKPQueueProvider->PKP\core\{closure}()
#28 {main}
[01-Feb-2024 21:01:08 Asia/Kolkata] #0 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(720): Illuminate\Database\Connection->runQueryCallback()
#1 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(577): Illuminate\Database\Connection->run()
#2 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Query/Builder.php(3340): Illuminate\Database\Connection->affectingStatement()
#3 /ojs/lib/pkp/classes/statistics/PKPTemporaryTotalsDAO.php(163): Illuminate\Database\Query\Builder->insertUsing()
#4 /ojs/jobs/statistics/CompileUsageStatsFromTemporaryRecords.php(103): PKP\statistics\PKPTemporaryTotalsDAO->compileSubmissionMetrics()
#5 /ojs/jobs/statistics/CompileUsageStatsFromTemporaryRecords.php(55): APP\jobs\statistics\CompileUsageStatsFromTemporaryRecords->compileMetrics()
#6 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(36): APP\jobs\statistics\CompileUsageStatsFromTemporaryRecords->handle()
#7 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/Util.php(41): Illuminate\Container\BoundMethod::Illuminate\Container\{closure}()
#8 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(93): Illuminate\Container\Util::unwrapIfClosure()
#9 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/BoundMethod.php(37): Illuminate\Container\BoundMethod::callBoundMethod()
#10 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Container/Container.php(661): Illuminate\Container\BoundMethod::call()
#11 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(128): Illuminate\Container\Container->call()
#12 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\Bus\Dispatcher->Illuminate\Bus\{closure}()
#13 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}()
#14 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Bus/Dispatcher.php(132): Illuminate\Pipeline\Pipeline->then()
#15 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(124): Illuminate\Bus\Dispatcher->dispatchNow()
#16 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(141): Illuminate\Queue\CallQueuedHandler->Illuminate\Queue\{closure}()
#17 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Pipeline/Pipeline.php(116): Illuminate\Pipeline\Pipeline->Illuminate\Pipeline\{closure}()
#18 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(126): Illuminate\Pipeline\Pipeline->then()
#19 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/CallQueuedHandler.php(70): Illuminate\Queue\CallQueuedHandler->dispatchThroughMiddleware()
#20 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Jobs/Job.php(98): Illuminate\Queue\CallQueuedHandler->call()
#21 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(425): Illuminate\Queue\Jobs\Job->fire()
#22 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(375): Illuminate\Queue\Worker->process()
#23 /ojs/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Queue/Worker.php(326): Illuminate\Queue\Worker->runJob()
#24 /ojs/lib/pkp/classes/core/PKPQueueProvider.php(104): Illuminate\Queue\Worker->runNextJob()
#25 /ojs/lib/pkp/classes/queue/JobRunner.php(220): PKP\core\PKPQueueProvider->runJobInQueue()
#26 /ojs/lib/pkp/classes/core/PKPQueueProvider.php(128): PKP\queue\JobRunner->processJobs()
#27 [internal function]: PKP\core\PKPQueueProvider->PKP\core\{closure}()
#28 {main}

Do I need to rollback the code?