From 00dd46906fc31188ec97809611da46394e01360d Mon Sep 17 00:00:00 2001 From: Alan Orth Date: Tue, 6 Apr 2021 22:33:43 +0300 Subject: [PATCH] Add notes for 2021-04-06 --- content/posts/2021-04.md | 178 +++++++++++++++++++++++ docs/2021-03/index.html | 4 +- docs/2021-04/index.html | 181 +++++++++++++++++++++++- docs/categories/index.html | 2 +- docs/categories/notes/index.html | 2 +- docs/categories/notes/page/2/index.html | 2 +- docs/categories/notes/page/3/index.html | 2 +- docs/categories/notes/page/4/index.html | 2 +- docs/categories/notes/page/5/index.html | 2 +- docs/index.html | 2 +- docs/page/2/index.html | 2 +- docs/page/3/index.html | 2 +- docs/page/4/index.html | 2 +- docs/page/5/index.html | 2 +- docs/page/6/index.html | 2 +- docs/page/7/index.html | 2 +- docs/posts/index.html | 2 +- docs/posts/page/2/index.html | 2 +- docs/posts/page/3/index.html | 2 +- docs/posts/page/4/index.html | 2 +- docs/posts/page/5/index.html | 2 +- docs/posts/page/6/index.html | 2 +- docs/posts/page/7/index.html | 2 +- docs/sitemap.xml | 12 +- 24 files changed, 384 insertions(+), 31 deletions(-) diff --git a/content/posts/2021-04.md b/content/posts/2021-04.md index b468cfa2f..ec55d5adf 100644 --- a/content/posts/2021-04.md +++ b/content/posts/2021-04.md @@ -144,4 +144,182 @@ $ grep downloads /tmp/page*.json | grep -o -E '[0-9]+,' | sed 's/,//' | xargs | - Views: 30721 - Downloads: 10205 +## 2021-04-06 + +- Margarita from CCAFS was having problems deleting an item from CGSpace again + - The error was "Authorization denied for action OBSOLETE (DELETE) on BITSTREAM:bd157345-448e ..." + - This is the same issue as last month +- Create a new collection on CGSpace for a new CIP project at Mishel Portilla's request +- I got a notice that CGSpace was down + - I didn't see anything strange at first, but there are an insane amount of database connections: + +```console +$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l +12413 +``` + +- The system journal shows thousands of these messages in the system journal, this is the first one: + +```console +Apr 06 07:52:13 linode18 tomcat7[556]: Apr 06, 2021 7:52:13 AM org.apache.tomcat.jdbc.pool.ConnectionPool abandon +``` + +- Around that time in the dspace log I see nothing unusual, but maybe these? + +```console +2021-04-06 07:52:29,409 INFO com.atmire.dspace.cua.CUASolrLoggerServiceImpl @ Updating : 200/127 docs in http://localhost:8081/solr/statistics +``` + +- (BTW what is the deal with the "200/127"? I should send a comment to Atmire) + - I file a ticket with Atmire: https://tracker.atmire.com/tickets-cgiar-ilri/view-tickets +- I restarted the PostgreSQL and Tomcat services and now I see less connections, but still WAY high: + +```console +$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l +3640 +$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l +2968 +$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l +13 +``` + +- After ten minutes or so it went back down... +- And now it's back up in the thousands... I am seeing a lot of stuff in dspace log like this: + +```console +2021-04-06 11:59:34,364 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717951 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717952 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717953 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717954 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717955 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717956 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717957 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717958 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717959 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717960 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717961 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717962 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717963 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717964 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717965 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717966 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717967 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717968 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717969 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717970 +2021-04-06 11:59:34,365 INFO org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717971 +``` + +- I sent some notes and a log to Atmire on our existing issue about the database stuff + - Also I asked them about the possibility of doing a formal review of Hibernate +- Falcon 3.0.0 was released so I updated the 3.0.0 branch for dspace-statistics-api and merged it to `v6_x` + - I also fixed one minor (unrelated) bug in the tests + - Then I deployed the new version on DSpace Test +- I had a meeting with Peter and Abenet about CGSpace TODOs +- CGSpace went down again and the PostgreSQL locks are through the roof: + +```console +$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l +12154 +``` + +- I don't see any activity on REST API, but in the last four hours there have been 3,500 DSpace sessions: + +```console +# grep -a -E '2021-04-06 (13|14|15|16|17):' /home/cgspace.cgiar.org/log/dspace.log.2021-04-06 | grep -o -E 'session_id=[A-Z0-9]{32}' | sort | uniq | wc -l +3547 +``` + +- I looked at the same time of day for the past few weeks and it seems to be a normal number of sessions: + +```console +# for file in /home/cgspace.cgiar.org/log/dspace.log.2021-0{3,4}-*; do grep -a -E "2021-0(3|4)-[0-9]{2} (13|14|15|16|17):" "$file" | grep -o -E 'session_id=[A-Z0-9]{32}' | sort | uniq | wc -l; done +... +3572 +4085 +3476 +3128 +2949 +2016 +1839 +4513 +3463 +4425 +3328 +2783 +3898 +3848 +7799 +255 +534 +2755 +599 +4463 +3547 +``` + +- What about total number of sessions per day? + +```console +# for file in /home/cgspace.cgiar.org/log/dspace.log.2021-0{3,4}-*; do echo "$file:"; grep -a -o -E 'session_id=[A-Z0-9]{32}' "$file" | sort | uniq | wc -l; done +... +/home/cgspace.cgiar.org/log/dspace.log.2021-03-28: +11784 +/home/cgspace.cgiar.org/log/dspace.log.2021-03-29: +15104 +/home/cgspace.cgiar.org/log/dspace.log.2021-03-30: +19396 +/home/cgspace.cgiar.org/log/dspace.log.2021-03-31: +32612 +/home/cgspace.cgiar.org/log/dspace.log.2021-04-01: +26037 +/home/cgspace.cgiar.org/log/dspace.log.2021-04-02: +14315 +/home/cgspace.cgiar.org/log/dspace.log.2021-04-03: +12530 +/home/cgspace.cgiar.org/log/dspace.log.2021-04-04: +13138 +/home/cgspace.cgiar.org/log/dspace.log.2021-04-05: +16756 +/home/cgspace.cgiar.org/log/dspace.log.2021-04-06: +12343 +``` + +- So it's not the number of sessions... it's something with the workload... +- I had to step away for an hour or so and when I came back the site was still down and there were still 12,000 locks + - I restarted postgresql and tomcat7... +- The locks in PostgreSQL shot up again... + +```console +$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l +3447 +$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l +3527 +$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l +4582 +``` + +- I don't know what the hell is going on +- While looking at the logs I see that MEL is trying to log into CGSpace's REST API and delete items: + +```console +34.209.213.122 - - [06/Apr/2021:03:50:46 +0200] "POST /rest/login HTTP/1.1" 401 727 "-" "MEL" +34.209.213.122 - - [06/Apr/2021:03:50:48 +0200] "DELETE /rest/items/95f52bf1-f082-4e10-ad57-268a76ca18ec/metadata HTTP/1.1" 401 704 "-" "-" +``` + +- I see a few of these per day going back several months +- Also annoying, I see tons of what look like penetration testing requests from Qualys: + +```console +2021-04-04 06:35:17,889 INFO org.dspace.authenticate.LDAPAuthentication @ anonymous:session_id=FF1E051BCA7D81CC5A807D85380D81E5:ip_addr=64.39.108.48:failed_login:no DN found for user "'> +2021-04-04 06:35:17,889 INFO org.dspace.authenticate.PasswordAuthentication @ anonymous:session_id=FF1E051BCA7D81CC5A807D85380D81E5:ip_addr=64.39.108.48:authenticate:attempting password auth of user="'> +2021-04-04 06:35:17,890 INFO org.dspace.app.xmlui.utils.AuthenticationUtil @ anonymous:session_id=FF1E051BCA7D81CC5A807D85380D81E5:ip_addr=64.39.108.48:failed_login:email="'>, realm=null, result=2 +2021-04-04 06:35:18,145 INFO org.dspace.authenticate.LDAPAuthentication @ anonymous:session_id=FF1E051BCA7D81CC5A807D85380D81E5:ip_addr=64.39.108.48:auth:attempting trivial auth of user=was@qualys.com +2021-04-04 06:35:18,519 INFO org.dspace.authenticate.LDAPAuthentication @ anonymous:session_id=FF1E051BCA7D81CC5A807D85380D81E5:ip_addr=64.39.108.48:failed_login:no DN found for user was@qualys.com +2021-04-04 06:35:18,520 INFO org.dspace.authenticate.PasswordAuthentication @ anonymous:session_id=FF1E051BCA7D81CC5A807D85380D81E5:ip_addr=64.39.108.48:authenticate:attempting password auth of user=was@qualys.com +``` + +- I deleted the ilri/AReS repository on GitHub since we haven't updated it in two years + - All development is happening in https://github.com/ilri/openRXV now + diff --git a/docs/2021-03/index.html b/docs/2021-03/index.html index 658809ae4..123139ecb 100644 --- a/docs/2021-03/index.html +++ b/docs/2021-03/index.html @@ -19,7 +19,7 @@ Also, we found some issues building and running OpenRXV currently due to ecosyst - + @@ -46,7 +46,7 @@ Also, we found some issues building and running OpenRXV currently due to ecosyst "url": "https://alanorth.github.io/cgspace-notes/2021-03/", "wordCount": "4452", "datePublished": "2021-03-01T10:13:54+02:00", - "dateModified": "2021-04-01T09:49:08+03:00", + "dateModified": "2021-04-05T19:36:44+03:00", "author": { "@type": "Person", "name": "Alan Orth" diff --git a/docs/2021-04/index.html b/docs/2021-04/index.html index 04fbc89e8..2018311c2 100644 --- a/docs/2021-04/index.html +++ b/docs/2021-04/index.html @@ -24,7 +24,7 @@ Perhaps one of the containers crashed, I should have looked closer but I was in - + @@ -54,9 +54,9 @@ Perhaps one of the containers crashed, I should have looked closer but I was in "@type": "BlogPosting", "headline": "April, 2021", "url": "https://alanorth.github.io/cgspace-notes/2021-04/", - "wordCount": "823", + "wordCount": "1789", "datePublished": "2021-04-01T09:50:54+03:00", - "dateModified": "2021-04-01T09:50:54+03:00", + "dateModified": "2021-04-05T19:36:44+03:00", "author": { "@type": "Person", "name": "Alan Orth" @@ -275,6 +275,181 @@ $ grep downloads /tmp/page*.json | grep -o -E '[0-9]+,' | sed 's/,//' | xargs | +

2021-04-06

+
    +
  • Margarita from CCAFS was having problems deleting an item from CGSpace again +
      +
    • The error was “Authorization denied for action OBSOLETE (DELETE) on BITSTREAM:bd157345-448e …”
      • +
    • This is the same issue as last month
      • +
    +
    • +
  • Create a new collection on CGSpace for a new CIP project at Mishel Portilla’s request
    • +
  • I got a notice that CGSpace was down +
      +
    • I didn’t see anything strange at first, but there are an insane amount of database connections:
      • +
    +
    • +
+
$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l
+12413
+
    +
  • The system journal shows thousands of these messages in the system journal, this is the first one:
    • +
+
Apr 06 07:52:13 linode18 tomcat7[556]: Apr 06, 2021 7:52:13 AM org.apache.tomcat.jdbc.pool.ConnectionPool abandon
+
    +
  • Around that time in the dspace log I see nothing unusual, but maybe these?
    • +
+
2021-04-06 07:52:29,409 INFO  com.atmire.dspace.cua.CUASolrLoggerServiceImpl @ Updating : 200/127 docs in http://localhost:8081/solr/statistics
+
+
$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l
+3640
+$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l
+2968
+$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l
+13
+
    +
  • After ten minutes or so it went back down…
    • +
  • And now it’s back up in the thousands… I am seeing a lot of stuff in dspace log like this:
    • +
+
2021-04-06 11:59:34,364 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717951
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717952
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717953
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717954
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717955
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717956
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717957
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717958
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717959
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717960
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717961
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717962
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717963
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717964
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717965
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717966
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717967
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717968
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717969
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717970
+2021-04-06 11:59:34,365 INFO  org.dspace.content.MetadataValueServiceImpl @ user.hidden@cgiar.org:session_id=65F32E67CE8E347F64EFB5EB4E349B9B:delete_metadata_value: metadata_value_id=5717971
+
    +
  • I sent some notes and a log to Atmire on our existing issue about the database stuff +
      +
    • Also I asked them about the possibility of doing a formal review of Hibernate
      • +
    +
    • +
  • Falcon 3.0.0 was released so I updated the 3.0.0 branch for dspace-statistics-api and merged it to v6_x +
      +
    • I also fixed one minor (unrelated) bug in the tests
      • +
    • Then I deployed the new version on DSpace Test
      • +
    +
    • +
  • I had a meeting with Peter and Abenet about CGSpace TODOs
    • +
  • CGSpace went down again and the PostgreSQL locks are through the roof:
    • +
+
$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l
+12154
+
    +
  • I don’t see any activity on REST API, but in the last four hours there have been 3,500 DSpace sessions:
    • +
+
# grep -a -E '2021-04-06 (13|14|15|16|17):' /home/cgspace.cgiar.org/log/dspace.log.2021-04-06 | grep -o -E 'session_id=[A-Z0-9]{32}' | sort | uniq | wc -l
+3547
+
    +
  • I looked at the same time of day for the past few weeks and it seems to be a normal number of sessions:
    • +
+
# for file in /home/cgspace.cgiar.org/log/dspace.log.2021-0{3,4}-*; do grep -a -E "2021-0(3|4)-[0-9]{2} (13|14|15|16|17):" "$file" | grep -o -E 'session_id=[A-Z0-9]{32}' | sort | uniq | wc -l; done
+...
+3572
+4085
+3476
+3128
+2949
+2016
+1839
+4513
+3463
+4425
+3328
+2783
+3898
+3848
+7799
+255
+534
+2755
+599
+4463
+3547
+
    +
  • What about total number of sessions per day?
    • +
+
# for file in /home/cgspace.cgiar.org/log/dspace.log.2021-0{3,4}-*; do echo "$file:"; grep -a -o -E 'session_id=[A-Z0-9]{32}' "$file" | sort | uniq | wc -l; done
+...
+/home/cgspace.cgiar.org/log/dspace.log.2021-03-28:
+11784
+/home/cgspace.cgiar.org/log/dspace.log.2021-03-29:
+15104
+/home/cgspace.cgiar.org/log/dspace.log.2021-03-30:
+19396
+/home/cgspace.cgiar.org/log/dspace.log.2021-03-31:
+32612
+/home/cgspace.cgiar.org/log/dspace.log.2021-04-01:
+26037
+/home/cgspace.cgiar.org/log/dspace.log.2021-04-02:
+14315
+/home/cgspace.cgiar.org/log/dspace.log.2021-04-03:
+12530
+/home/cgspace.cgiar.org/log/dspace.log.2021-04-04:
+13138
+/home/cgspace.cgiar.org/log/dspace.log.2021-04-05:
+16756
+/home/cgspace.cgiar.org/log/dspace.log.2021-04-06:
+12343
+
    +
  • So it’s not the number of sessions… it’s something with the workload…
    • +
  • I had to step away for an hour or so and when I came back the site was still down and there were still 12,000 locks +
      +
    • I restarted postgresql and tomcat7…
      • +
    +
    • +
  • The locks in PostgreSQL shot up again…
    • +
+
$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l
+3447
+$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l
+3527
+$ psql -c 'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;' | wc -l
+4582
+
    +
  • I don’t know what the hell is going on
    • +
  • While looking at the logs I see that MEL is trying to log into CGSpace’s REST API and delete items:
    • +
+
34.209.213.122 - - [06/Apr/2021:03:50:46 +0200] "POST /rest/login HTTP/1.1" 401 727 "-" "MEL"
+34.209.213.122 - - [06/Apr/2021:03:50:48 +0200] "DELETE /rest/items/95f52bf1-f082-4e10-ad57-268a76ca18ec/metadata HTTP/1.1" 401 704 "-" "-"
+
    +
  • I see a few of these per day going back several months
    • +
  • Also annoying, I see tons of what look like penetration testing requests from Qualys:
    • +
+
2021-04-04 06:35:17,889 INFO  org.dspace.authenticate.LDAPAuthentication @ anonymous:session_id=FF1E051BCA7D81CC5A807D85380D81E5:ip_addr=64.39.108.48:failed_login:no DN found for user "'><qss a=X158062356Y1_2Z>
+2021-04-04 06:35:17,889 INFO  org.dspace.authenticate.PasswordAuthentication @ anonymous:session_id=FF1E051BCA7D81CC5A807D85380D81E5:ip_addr=64.39.108.48:authenticate:attempting password auth of user="'><qss a=X158062356Y1_2Z>
+2021-04-04 06:35:17,890 INFO  org.dspace.app.xmlui.utils.AuthenticationUtil @ anonymous:session_id=FF1E051BCA7D81CC5A807D85380D81E5:ip_addr=64.39.108.48:failed_login:email="'><qss a=X158062356Y1_2Z>, realm=null, result=2
+2021-04-04 06:35:18,145 INFO  org.dspace.authenticate.LDAPAuthentication @ anonymous:session_id=FF1E051BCA7D81CC5A807D85380D81E5:ip_addr=64.39.108.48:auth:attempting trivial auth of user=was@qualys.com
+2021-04-04 06:35:18,519 INFO  org.dspace.authenticate.LDAPAuthentication @ anonymous:session_id=FF1E051BCA7D81CC5A807D85380D81E5:ip_addr=64.39.108.48:failed_login:no DN found for user was@qualys.com
+2021-04-04 06:35:18,520 INFO  org.dspace.authenticate.PasswordAuthentication @ anonymous:session_id=FF1E051BCA7D81CC5A807D85380D81E5:ip_addr=64.39.108.48:authenticate:attempting password auth of user=was@qualys.com
+
    +
  • I deleted the ilri/AReS repository on GitHub since we haven’t updated it in two years + +
    • +
diff --git a/docs/categories/index.html b/docs/categories/index.html index 4b9eaf56f..76e7604f9 100644 --- a/docs/categories/index.html +++ b/docs/categories/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/categories/notes/index.html b/docs/categories/notes/index.html index fac6c7fa5..2af5b64d9 100644 --- a/docs/categories/notes/index.html +++ b/docs/categories/notes/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/categories/notes/page/2/index.html b/docs/categories/notes/page/2/index.html index 0ebc70cc3..a0a69532b 100644 --- a/docs/categories/notes/page/2/index.html +++ b/docs/categories/notes/page/2/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/categories/notes/page/3/index.html b/docs/categories/notes/page/3/index.html index 746623c28..cf3025562 100644 --- a/docs/categories/notes/page/3/index.html +++ b/docs/categories/notes/page/3/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/categories/notes/page/4/index.html b/docs/categories/notes/page/4/index.html index 166bda639..3e409d3b2 100644 --- a/docs/categories/notes/page/4/index.html +++ b/docs/categories/notes/page/4/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/categories/notes/page/5/index.html b/docs/categories/notes/page/5/index.html index cd0ae0468..f168a0cd1 100644 --- a/docs/categories/notes/page/5/index.html +++ b/docs/categories/notes/page/5/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/index.html b/docs/index.html index a0dc27c04..7d5ee09ae 100644 --- a/docs/index.html +++ b/docs/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/page/2/index.html b/docs/page/2/index.html index cc17f8ced..9ffea1160 100644 --- a/docs/page/2/index.html +++ b/docs/page/2/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/page/3/index.html b/docs/page/3/index.html index f7952361e..829216560 100644 --- a/docs/page/3/index.html +++ b/docs/page/3/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/page/4/index.html b/docs/page/4/index.html index 5337cbc03..4d1a3548f 100644 --- a/docs/page/4/index.html +++ b/docs/page/4/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/page/5/index.html b/docs/page/5/index.html index d3863e60b..b21941edc 100644 --- a/docs/page/5/index.html +++ b/docs/page/5/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/page/6/index.html b/docs/page/6/index.html index cefeaa054..29f037222 100644 --- a/docs/page/6/index.html +++ b/docs/page/6/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/page/7/index.html b/docs/page/7/index.html index 3afbb8db5..3b5e332cf 100644 --- a/docs/page/7/index.html +++ b/docs/page/7/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/posts/index.html b/docs/posts/index.html index 8fa6d129f..7a221d317 100644 --- a/docs/posts/index.html +++ b/docs/posts/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/posts/page/2/index.html b/docs/posts/page/2/index.html index 6d75c637a..13002c5c2 100644 --- a/docs/posts/page/2/index.html +++ b/docs/posts/page/2/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/posts/page/3/index.html b/docs/posts/page/3/index.html index 0f12eea5d..3d3898e7c 100644 --- a/docs/posts/page/3/index.html +++ b/docs/posts/page/3/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/posts/page/4/index.html b/docs/posts/page/4/index.html index 8e21b8f1c..53798ca46 100644 --- a/docs/posts/page/4/index.html +++ b/docs/posts/page/4/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/posts/page/5/index.html b/docs/posts/page/5/index.html index c4b687672..f2ff4d818 100644 --- a/docs/posts/page/5/index.html +++ b/docs/posts/page/5/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/posts/page/6/index.html b/docs/posts/page/6/index.html index 769787952..94837097f 100644 --- a/docs/posts/page/6/index.html +++ b/docs/posts/page/6/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/posts/page/7/index.html b/docs/posts/page/7/index.html index ba0b27f56..1b3d18ca1 100644 --- a/docs/posts/page/7/index.html +++ b/docs/posts/page/7/index.html @@ -10,7 +10,7 @@ - + diff --git a/docs/sitemap.xml b/docs/sitemap.xml index 40d30caf8..fa30257cf 100644 --- a/docs/sitemap.xml +++ b/docs/sitemap.xml @@ -3,22 +3,22 @@ xmlns:xhtml="http://www.w3.org/1999/xhtml"> https://alanorth.github.io/cgspace-notes/2021-04/ - 2021-04-01T09:50:54+03:00 + 2021-04-05T19:36:44+03:00 https://alanorth.github.io/cgspace-notes/categories/ - 2021-04-01T09:50:54+03:00 + 2021-04-05T19:36:44+03:00 https://alanorth.github.io/cgspace-notes/ - 2021-04-01T09:50:54+03:00 + 2021-04-05T19:36:44+03:00 https://alanorth.github.io/cgspace-notes/categories/notes/ - 2021-04-01T09:50:54+03:00 + 2021-04-05T19:36:44+03:00 https://alanorth.github.io/cgspace-notes/posts/ - 2021-04-01T09:50:54+03:00 + 2021-04-05T19:36:44+03:00 https://alanorth.github.io/cgspace-notes/2021-03/ - 2021-04-01T09:49:08+03:00 + 2021-04-05T19:36:44+03:00 https://alanorth.github.io/cgspace-notes/cgspace-cgcorev2-migration/ 2021-03-30T09:56:38+03:00