[OJS 3.3.0.3] Reports barely working and very slow

I had to take generate a few reports lately and notice two things:

  1. Those links don’t go anywhere, I just get a blank page:
    image

  2. Trying to load the COUNTER reports page (/stats/reports/report?pluginName=CounterReportPlugin) is absurdly slow. It took around 20 minutes just to load this page. By comparison, download a report (R3 from 2020) around the same time. So it took about one hour to load the page and two reports.

My metrics table has 7 988 338 entries and 2.9 GiB.

Is there something that I can do? Why is that so slow?

Hi @luizborges,

Is there anything in your PHP error log that might point to any reason why it is being slow?

-Roger
PKP Team

@rcgillis no relevant errors, it is just really slow.

I just restarted the server and the database server now and tested it, I’m using this setting on my php.ini:

error_reporting = E_ERROR|E_CORE_ERROR|E_COMPILE_ERROR|E_USER_ERROR|E_RECOVERABLE_ERROR|E_WARNING

I only got those errors during the requests:

[Wed Jun 30 10:10:01.214715 2021] [mpm_prefork:notice] [pid 80165] AH00169: caught SIGTERM, shutting down
[Wed Jun 30 10:10:01.424934 2021] [mpm_prefork:notice] [pid 69756] AH00163: Apache/2.4.48 (FreeBSD) OpenSSL/1.1.1k PHP/7.4.19 configured -- resuming normal operations
[Wed Jun 30 10:10:01.424999 2021] [core:notice] [pid 69756] AH00094: Command line: '/usr/local/sbin/httpd -D NOHTTPACCEPT'
[Wed Jun 30 10:14:10.601918 2021] [php7:notice] [pid 69688] [client 168.181.249.26:63500] ojs2: 404 Not Found
[Wed Jun 30 10:14:10.865988 2021] [php7:warn] [pid 77526] [client 13.114.235.183:8314] PHP Warning:  session_destroy(): Session object destruction failed in /usr/home/luizborges/www/public_html/lib/pkp/classes/session/SessionManager.inc.php on line 76
[Wed Jun 30 10:14:10.867547 2021] [php7:error] [pid 77526] [client 13.114.235.183:8314] PHP Fatal error:  Uncaught PDOException: SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry '729n3rvhtf7888jk6t4mab2jki' for key 'sessions.sessions_pkey' in /usr/home/luizborges/www/public_html/lib/pkp/lib/vendor/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOStatement.php:115\nStack trace:\n#0 /usr/home/luizborges/www/public_html/lib/pkp/lib/vendor/doctrine/dbal/lib/Doctrine/DBAL/Driver/PDOStatement.php(115): PDOStatement->execute(NULL)\n#1 /usr/home/luizborges/www/public_html/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(489): Doctrine\\DBAL\\Driver\\PDOStatement->execute()\n#2 /usr/home/luizborges/www/public_html/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(664): Illuminate\\Database\\Connection->Illuminate\\Database\\{closure}('INSERT INTO ses...', Array)\n#3 /usr/home/luizborges/www/public_html/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php(631): Illuminate\\Database\\Connection->runQueryCallback('INSERT INTO ses...', Array, Object(C in /usr/home/luizborges/www/public_html/lib/pkp/lib/vendor/laravel/framework/src/Illuminate/Database/Connection.php on line 671
[Wed Jun 30 10:14:10.890691 2021] [php7:notice] [pid 53943] [client 168.181.249.26:63503] ojs2: 404 Not Found
[Wed Jun 30 10:14:11.289925 2021] [php7:notice] [pid 31300] [client 168.181.249.26:63506] ojs2: 404 Not Found
[Wed Jun 30 10:14:11.621123 2021] [php7:notice] [pid 53943] [client 168.181.249.26:63508] ojs2: 404 Not Found
[Wed Jun 30 10:14:13.816009 2021] [php7:warn] [pid 57369] [client 172.105.242.107:54940] PHP Warning:  session_destroy(): Session object destruction failed in /usr/home/luizborges/www/public_html/lib/pkp/classes/session/SessionManager.inc.php on line 76
[Wed Jun 30 10:14:16.876093 2021] [php7:warn] [pid 57369] [client 172.105.242.107:54940] PHP Warning:  session_destroy(): Session object destruction failed in /usr/home/luizborges/www/public_html/lib/pkp/classes/session/SessionManager.inc.php on line 76
[Wed Jun 30 10:20:20.116290 2021] [php7:notice] [pid 96555] [client 157.55.39.96:7360] ojs2: 404 Not Found
[Wed Jun 30 10:20:53.280972 2021] [autoindex:error] [pid 93830] [client 187.36.177.15:1098] AH01276: Cannot serve directory /usr/home/luizborges/www/public_html/public/journals/23/: No matching DirectoryIndex (index.html,index.php) found, and server-generated directory index forbidden by Options directive, referer: https://periodicos.fclar.unesp.br/redd/article/view/6956
[Wed Jun 30 10:22:38.364522 2021] [php7:notice] [pid 36860] [client 66.249.64.6:39201] ojs2: 404 Not Found
[Wed Jun 30 10:24:16.638038 2021] [php7:notice] [pid 89371] [client 207.46.13.77:2432] ojs2: 404 Not Found
[Wed Jun 30 10:24:19.777553 2021] [php7:notice] [pid 98436] [client 207.46.13.163:6976] ojs2: 404 Not Found
[Wed Jun 30 10:27:35.788163 2021] [php7:notice] [pid 13136] [client 173.252.127.112:48662] ojs2: 404 Not Found
[Wed Jun 30 10:27:37.287980 2021] [php7:notice] [pid 6987] [client 173.252.127.118:55488] ojs2: 404 Not Found
[Wed Jun 30 10:27:37.347443 2021] [php7:notice] [pid 68] [client 173.252.127.17:36244] ojs2: 404 Not Found
[Wed Jun 30 10:27:41.629781 2021] [php7:notice] [pid 80454] [client 173.252.127.27:59814] ojs2: 404 Not Found
[Wed Jun 30 10:32:33.838574 2021] [php7:notice] [pid 2811] [client 66.249.64.6:51374] ojs2: 404 Not Found
[Wed Jun 30 10:36:09.685690 2021] [php7:notice] [pid 58055] [client 103.148.172.25:64767] ojs2: 404 Not Found
[Wed Jun 30 10:36:18.514432 2021] [php7:notice] [pid 25994] [client 66.249.64.8:63272] ojs2: 404 Not Found
[Wed Jun 30 10:37:35.387705 2021] [php7:notice] [pid 24175] [client 66.249.64.8:60333] ojs2: 404 Not Found
[Wed Jun 30 10:38:32.335028 2021] [php7:notice] [pid 25994] [client 66.249.64.10:60701] ojs2: 404 Not Found
[Wed Jun 30 10:41:44.615039 2021] [autoindex:error] [pid 58055] [client 187.36.177.15:1482] AH01276: Cannot serve directory /usr/home/luizborges/www/public_html/public/journals/23/: No matching DirectoryIndex (index.html,index.php) found, and server-generated directory index forbidden by Options directive, referer: https://periodicos.fclar.unesp.br/redd/article/view/6956
[Wed Jun 30 10:44:56.065644 2021] [autoindex:error] [pid 69] [client 187.36.177.15:1512] AH01276: Cannot serve directory /usr/home/luizborges/www/public_html/public/journals/23/: No matching DirectoryIndex (index.html,index.php) found, and server-generated directory index forbidden by Options directive, referer: https://periodicos.fclar.unesp.br/redd/issue/view/541
[Wed Jun 30 10:44:56.692168 2021] [php7:notice] [pid 45890] [client 66.249.64.6:43660] ojs2: 404 Not Found
[Wed Jun 30 10:49:28.162616 2021] [php7:notice] [pid 89514] [client 177.184.237.76:56430] ojs2: 404 Not Found
[Wed Jun 30 10:49:28.703255 2021] [php7:notice] [pid 74435] [client 177.184.237.76:42979] ojs2: 404 Not Found
[Wed Jun 30 10:49:29.567104 2021] [php7:notice] [pid 74435] [client 177.184.237.76:56436] ojs2: 404 Not Found
[Wed Jun 30 10:49:30.162024 2021] [php7:notice] [pid 95519] [client 177.184.237.76:56438] ojs2: 404 Not Found
[Wed Jun 30 10:49:53.615566 2021] [php7:notice] [pid 98531] [client 66.249.64.8:58081] ojs2: 404 Not Found
[Wed Jun 30 10:50:20.343141 2021] [php7:notice] [pid 45144] [client 2804:d59:9105:c500:68ee:24e4:41ef:74cc:62871] ojs2: 404 Not Found
[Wed Jun 30 10:50:30.006063 2021] [php7:notice] [pid 91411] [client 54.236.1.13:8762] ojs2: 404 Not Found
[Wed Jun 30 10:50:54.026437 2021] [php7:notice] [pid 91411] [client 2804:d59:9105:c500:68ee:24e4:41ef:74cc:63016] ojs2: 404 Not Found
[Wed Jun 30 10:51:00.890848 2021] [php7:notice] [pid 19342] [client 66.249.64.6:44827] ojs2: 404 Not Found
[Wed Jun 30 10:52:40.011900 2021] [autoindex:error] [pid 12563] [client 2804:18:181b:bc7e:6523:6669:6378:e2af:61070] AH01276: Cannot serve directory /usr/home/luizborges/www/public_html/public/journals/23/: No matching DirectoryIndex (index.html,index.php) found, and server-generated directory index forbidden by Options directive, referer: https://periodicos.fclar.unesp.br/redd/article/view/6912
[Wed Jun 30 10:54:06.194743 2021] [autoindex:error] [pid 47769] [client 187.36.177.15:1168] AH01276: Cannot serve directory /usr/home/luizborges/www/public_html/public/journals/23/: No matching DirectoryIndex (index.html,index.php) found, and server-generated directory index forbidden by Options directive, referer: https://periodicos.fclar.unesp.br/redd/article/view/6956
[Wed Jun 30 10:55:05.733020 2021] [autoindex:error] [pid 45730] [client 187.36.177.15:1187] AH01276: Cannot serve directory /usr/home/luizborges/www/public_html/public/journals/23/: No matching DirectoryIndex (index.html,index.php) found, and server-generated directory index forbidden by Options directive, referer: https://periodicos.fclar.unesp.br/redd/issue/view/541
[Wed Jun 30 10:57:57.599818 2021] [php7:notice] [pid 19251] [client 2a03:2880:20ff:8::face:b00c:42406] ojs2: 404 Not Found
[Wed Jun 30 11:00:15.087360 2021] [php7:notice] [pid 71098] [client 40.77.167.26:65088] ojs2: 404 Not Found
[Wed Jun 30 11:03:12.973086 2021] [autoindex:error] [pid 68098] [client 191.220.112.224:52643] AH01276: Cannot serve directory /usr/home/luizborges/www/public_html/public/journals/23/: No matching DirectoryIndex (index.html,index.php) found, and server-generated directory index forbidden by Options directive, referer: https://periodicos.fclar.unesp.br/redd/article/view/4390
[Wed Jun 30 11:04:11.647769 2021] [php7:notice] [pid 52456] [client 66.249.64.8:37263] ojs2: 404 Not Found

The COUNTER page took around 10 minutes to load, in the log reported the request at 10:10:50 but it was logged after 10:20:58:

IP_REMOVED - - [30/Jun/2021:10:20:58 -0300] "GET /plugins/themes/default/js/lib/popper/popper.js?v=3.3.0.3 HTTP/1.1" 200 81675
IP_REMOVED - - [30/Jun/2021:10:10:50 -0300] "GET /alfa/stats/reports/report?pluginName=CounterReportPlugin HTTP/1.1" 200 27329

And the COUNTER reporter V3 from 2020 took almost 40 minutes to load (logged the request at 10:25 after 11:03):

IP_REMOVED - - [30/Jun/2021:11:03:13 -0300] "GET /rpge/article/download/9366/6217/25584 HTTP/1.1" 200 246047
IP_REMOVED - - [30/Jun/2021:10:25:54 -0300] "GET /alfa/stats/reports/report?pluginName=CounterReportPlugin&type=report&year=2020 HTTP/1.1" 200 3686

Just for completion, here is the generated report:

"Relatório 1 (R3)"
"Número de solicitaçõesi de texto-completo bem-sucedidas a artigos por mês e revista (Ano 2020)"

"Data da execução:"
2021-06-30
,Editora,Plataforma,"ISSN impresso","ISSN eletrônico",Jan-2020,Feb-2020,Mar-2020,Apr-2020,May-2020,Jun-2020,Jul-2020,Aug-2020,Sep-2020,Oct-2020,Nov-2020,Dec-2020,"Total YTD","HTML YTD","PDF YTD"
"Total para todas as revistas",-,,-,-,43330,65237,95663,95140,120430,104088,148945,183731,170577,237877,99935,93895,1458848,0,1440382
"Perspectivas: Revista de Ciências Sociais","Universidade Estadual Paulista / UNESP","Open Journal Systems",0101-3459,1984-0241,2925,4528,7406,7568,11087,9733,14123,16078,14583,19890,9243,8636,125800,0,125800
"Revista de Letras",,"Open Journal Systems",0101-3505,1981-7886,1276,1618,2285,2552,3149,3326,5343,6245,6280,8201,2422,2210,44907,0,44907
"Estudos de Sociologia","FCL-UNESP Laboratório Editorial","Open Journal Systems",1414-0144,1982-4718,2864,3759,5344,5547,6987,5703,9158,11135,9557,14629,5121,5506,85310,0,85310
"ITINERÁRIOS – Revista de Literatura",,"Open Journal Systems",0103-815X,,3504,6337,9382,8644,12830,8302,12511,15976,13702,20886,7698,8203,127975,0,127975
"Revista Segurança Urbana e Juventude",,"Open Journal Systems",,1984-5103,180,263,303,428,505,509,811,959,895,1291,391,357,6892,0,6892
"Revista Ibero-Americana de Estudos em Educação","Faculdade de Ciências e Letras/Unesp","Open Journal Systems",,1982-5587,8759,12378,15031,14546,21488,16510,26581,39365,30275,41998,17356,13686,257973,0,248857
"CASA: Cadernos de Semiótica Aplicada","Laboratório Editorial FCL-UNESP","Open Journal Systems",,1679-3404,1810,1622,2917,2603,2853,3259,4004,5014,4621,6589,1998,2045,39335,0,39193
"REDD – Revista Espaço de Diálogo e Desconexão","UNESP - Universidade Estadual Paulista / Araraquara","Open Journal Systems",,1984-1736,871,1530,2369,2281,2878,2764,4219,4978,5480,7320,2520,2501,39711,0,39711
"Lettres Françaises",,"Open Journal Systems",1414-025X,2526-2955,785,857,1431,1688,1914,1423,3186,3405,3123,4904,1325,1766,25807,0,25807
"ALFA: Revista de Linguística",UNESP,"Open Journal Systems",,1981-5794,7371,13110,19747,20738,22423,19735,25403,28038,28302,40143,17428,18054,260492,0,260492
"Cadernos de Campo: Revista de Ciências Sociais","Faculdade de Ciências e Letras - Unesp - Araraquara.","Open Journal Systems",1415-0689,2359-2419,1811,2494,4204,3798,4981,3969,6399,7779,8971,9708,4142,4361,62617,0,62617
"Temas de Administração Pública",,"Open Journal Systems",,1982-4637,653,1158,1570,1651,1915,1821,2661,2814,2945,3935,9,1,21133,0,21133
"Revista Iniciativa Econômica","Departamento de Economia","Open Journal Systems",,2358-5951,204,377,783,889,1297,1121,1242,1504,2052,2723,1413,1626,15231,0,15231
"Revista Sem Aspas ","Laboratório Editorial Faculdade de Ciências  e Letras","Open Journal Systems",,2358-4238,903,1595,2908,2493,3311,3638,4980,5102,5312,6791,4269,3911,45213,0,45213
"Revista EntreLínguas","Universidade Estadual Paulista","Open Journal Systems",,2447-3529,686,928,1023,876,1324,1352,2603,3359,2332,4026,1305,1458,21272,0,20312
"Revista on line de Política e Gestão Educacional","Editora Ibero-Americana de Educação","Open Journal Systems",,1519-9029,6241,8260,12077,10651,12128,12721,15611,18986,18554,26130,12717,10658,164734,0,156670
"Temas em Educação e Saúde ","Editora Ibero-Americana de Educação","Open Journal Systems",1517-7947,2526-3471,1604,2851,4906,5572,6307,5443,6795,8028,8411,11790,6797,5659,74163,0,73979
"DOXA: Revista Brasileira de Psicologia e Educação","Editora Ibero-Americana de Educação","Open Journal Systems",,2594-8385,883,1572,1977,2615,3053,2759,3315,4966,5182,6923,3781,3257,40283,0,40283

Hi @luizborges,

Thank you for providing this additional information. I’m not sure what exactly might be causing the slow-ness, but I will flag this with the rest of our team, who respond when they are able to.

Best regards,

Roger
PKP Team