[OJS 3.3.0.3] Reports barely working and very slow

Software Support
1

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
    image957×759 35.7 KB

  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?

2

Hi @luizborges,

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

-Roger
PKP Team

3

@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
4

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

5

Hello,
I’m raising a dead post here, but the issue still remains problematic on 3.3.0.13. The COUNTER Reports page take long time to just load (around 30 minutes), and the reports itself even longer (I’ve be waiting for 30 minutes and it still isn’t done).

Will 3.4 address the COUNTER reports in anyway?

6

Hi @luizborges,

Are you able to check to see if there are any fresh error log messages related to this?

-Roger
PKP Team

7

@rcgillis no errors related to that in the logs.

8

Hi @luizborges,

Okay. Thanks - I’ve asked our systems/dev folks to have a look at this when they have an opportunity, so hopefully you’ll hear from one of them soon.

-Roger
PKP Team

9

One of our devs have noted that this has been rewritten in OJS 3.4.0-x, so you might want to consider upgrading. But, @bozana - do you have any insights if this would be fixable in 3.3?

-Roger

11

Hi all,
Yes, this is an old code and you seem to have lots of data in the metrics table @luizborges.
I will ping @ctgraham, that developed this plugin, if he would know something/more or about similar cases. But I do not think we can do much for 3.3.
But, we have rewritten usage statistics code and reports in 3.4. COUNTER R3 is not supported there any more, but COUNTER R4 still is, and there is now also support for COUNTER R5 (UI coming soon, currently only via SUSHI interface), as well as the possibility to download OJS internal reports (via Statistics > Articles).

Best,
Bozana

12

@luizborges, maybe just a tiny help: you could remember the URLs of the reports that you would like to have, change the parameter (e.g. the year) there, and use them directly in the browser. This way you would only skip that long loading of the first/landing page. However, as you said, also the report download takes too long in your case.

13

We just download this specific report one a year, and by next year I will already be on 3.4 (maybe 4.x???), I’m just bringing this up to see if there was any changes in the new edition.

I understand that legacy code is very hard to deal with.