<li>The current time on the server is 08:52 and I see the dspaceCli locks were started at 04:00 and 05:00… so I need to check which cron jobs those belong to as I think I noticed this last month too
<ul>
<li>I’m going to wait and see if they finish, but by tomorrow I will kill them</li>
<li>The load on the server is now very low and there are no more locks from dspaceCli
<ul>
<li>So there <em>was</em> some long-running process that was running and had to finish!</li>
<li>That finally sheds some light on the “high load on Sunday” problem where I couldn’t find any other distinct pattern in the nginx or Tomcat requests</li>
</ul>
</li>
</ul>
<h2id="2023-01-03">2023-01-03</h2>
<ul>
<li>The load from the server on Sundays, which I have noticed for a long time, seems to be coming from the DSpace checker cron job
<ul>
<li>This checks the checksums of all bitstreams to see if they match the ones in the database</li>
</ul>
</li>
<li>I exported the entire CGSpace metadata to do country/region checks with <code>csv-metadata-quality</code>
<ul>
<li>I extracted only the items with countries, which was about 48,000, then split the file into parts of 10,000 items, but the upload found 2,000 changes in the first one and took several hours to complete…</li>
</ul>
</li>
<li>IWMI sent me ORCID identifiers for new scientsts, bringing our total to 2,010</li>
</ul>
<h2id="2023-01-04">2023-01-04</h2>
<ul>
<li>I finally finished applying the region imports (in five batches of 10,000)
<ul>
<li>It was about 7,500 missing regions in total…</li>
</ul>
</li>
<li>Now I will move on to doing the Initiative mappings
<ul>
<li>I modified my <code>fix-initiative-mappings.py</code> script to only write out the items that have updated mappings</li>
<li>This makes it way easier to apply fixes to the entire CGSpace because we don’t try to import 100,000 items with no changes in mappings</li>
</ul>
</li>
<li>More dspaceCli locks from 04:00 this morning (current time on server is 07:33) and today is a Wednesday
<ul>
<li>The checker cron job runs on <code>0,3</code>, which is Sunday and Wednesday, so this is from that…</li>
<li>Finally at 16:30 I decided to kill the PIDs associated with those locks…</li>
<li>I am going to disable that cron job for now and watch the server load for a few weeks</li>
<li>It’s Sunday and I see some PostgreSQL locks belonging to dspaceCli that started at 05:00
<ul>
<li>That’s strange because I disabled the <code>dspace checker</code> one last week, so I’m not sure which this is…</li>
<li>It’s currently 2:30PM on the server so these locks have been there for almost twelve hours</li>
</ul>
</li>
<li>I exported the entire CGSpace to update the Initiative mappings
<ul>
<li>Items were mapped to ~58 new Initiative collections</li>
</ul>
</li>
<li>Then I ran the ORCID import to catch any new ones that might not have been tagged</li>
<li>Then I started a harvest on AReS</li>
</ul>
<h2id="2023-01-09">2023-01-09</h2>
<ul>
<li>Fix some invalid Initiative names on CGSpace and then check for missing mappings</li>
<li>Check for missing regions in the Initiatives collection</li>
<li>Export a list of author affiliations from the Initiatives community for Peter to check
<ul>
<li>Was slightly ghetto because I did it from a CSV export of the Initiatives community, then imported to OpenRefine to split multi-value fields, then did some sed nonsense to handle the quoting:</li>
<li>While following onathe <ahref="https://github.com/DSpace/RestContract/blob/main/authentication.md">DSpace 7 REST API authentication docs</a> I still cannot log in via curl on the command line because I get a <code>Access is denied. Invalid CSRF token.</code> message</li>
<li>Logging in via the HAL Browser works…</li>
<li>Someone on the DSpace Slack mentioned that the <ahref="https://github.com/DSpace/RestContract/issues/209">authentication documentation is out of date</a> and we need to specify the cookie too</li>
<li>Batch import four IFPRI items for CGIAR Initiative on Low-Emission Food Systems</li>
<li>Batch import another twenty-eight items for IFPRI across several Initiatives
<ul>
<li>On this one I did quite a bit of extra work to check for CRPs and data/code URLs in the acknowledgements, licenses, volume/issue/extent, etc</li>
<li>I fixed some authors, an ISBN, and added extra AGROVOC keywords from the abstracts</li>
<li>Then I checked for duplicates and ran it through csv-metadata-quality to make sure the countries/regions matched and there were no duplicate metadata values</li>
</ul>
</li>
</ul>
<h2id="2023-01-17">2023-01-17</h2>
<ul>
<li>Batch import another twenty-three items for IFPRI across several Initiatives
<ul>
<li>I checked the IFPRI eBrary for extra CRPs and data/code URLs in the acknowledgements, licenses, volume/issue/extent, etc</li>
<li>I fixed some authors, an ISBN, and added extra AGROVOC keywords from the abstracts</li>
<li>Then I found and removed one duplicate in these items, as well as another on CGSpace already (!): 10568/126669</li>
<li>Then I ran it through csv-metadata-quality to make sure the countries/regions matched and there were no duplicate metadata values</li>
</ul>
</li>
<li>I exported the Initiatives collection to check the mappings, regions, and other metadata with csv-metadata-quality</li>
<li>I also added a bunch of ORCID identifiers to my list and tagged 837 new metadata values on CGSpace</li>
<li>There is a high load on CGSpace pretty regularly
<ul>
<li>Looking at Munin it shows there is a marked increase in DSpace sessions the last few weeks:</li>
<li>I ran the IPs through my <code>resolve-addresses-geoip2.py</code> script to resolve their ASNs/networks, then extracted some lists of data center ISPs by eyeballing them (Amazon, Google, Microsoft, Apple, DigitalOcean, HostRoyale, and a dozen others):</li>
<li>But still, it’s suspicious that there are so many PostgreSQL locks</li>
<li>Looking at the Solr stats to check the hits the last month (actually I skipped December because I was so busy)
<ul>
<li>I see 31.148.223.10 is on ALFA TELECOM s.r.o. in Russia and it made 43,000 requests this month (and 400,000 more last month!)</li>
<li>I see 18.203.245.60 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 3.249.192.212 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 34.244.160.145 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 52.213.59.101 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 91.209.8.29 is in Bulgaria on DGM EOOD and is low risk according to Scamlytics, but their user agent is all lower case and it’s a data center ISP so nope</li>
<li>I see 54.78.176.127 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 54.246.128.111 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 54.74.197.53 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 52.16.103.133 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 63.32.99.252 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 176.34.141.181 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 34.243.17.80 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 34.240.206.16 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 18.203.81.120 is on Amazon and it uses weird user agents, different with each request</li>
<li>I see 176.97.210.106 is on Tube Hosting and is rate VERY BAD, malicious, scammy on everything I checked</li>
<li>I see 79.110.73.54 is on ALFA TELCOM / Serverel and is using a different, weird user agent with each request</li>
<li>There are too many to count… so I will purge these and then move on to user agents</li>
</span></span></span><spanstyle="display:flex;"><span><spanstyle="color:#960050;background-color:#1e0010"></span>Total number of bot hits purged: 466826
</span></span></code></pre></div><ul>
<li>Looking at user agents in Solr statistics from 2022-12 and 2023-01 I see some weird ones:
<ul>
<li><code>azure-logic-apps/1.0 (workflow e1f855704d6543f48be6205c40f4083f; version 08585300079823949478) microsoft-flow/1.0</code></li>
<li><code>Gov employment data scraper ([[your email]])</code></li>
<li>I’m looking at all the ORCID identifiers in the database, which seem to be way more than I realized:</li>
</ul>
<divclass="highlight"><pretabindex="0"style="color:#f8f8f2;background-color:#272822;-moz-tab-size:4;-o-tab-size:4;tab-size:4;"><codeclass="language-console"data-lang="console"><spanstyle="display:flex;"><span>localhost/dspacetest= ☘ \COPY (SELECT DISTINCT(text_value) FROM metadatavalue WHERE dspace_object_id IN (SELECT uuid FROM item) AND metadata_field_id=247) to /tmp/2023-01-18-orcid-identifiers.txt;
<li>In the DSpace logs I see some weird SQL messages, so I decided to restart PostgreSQL and Tomcat 7…
<ul>
<li>I hope this doesn’t cause some issue with in-progress workflows…</li>
</ul>
</li>
<li>I see another user on Cox in the US (98.186.216.144) crawling and scraping XMLUI with Python
<ul>
<li>I will add python to the list of bad bot user agents in nginx</li>
</ul>
</li>
<li>While looking into the locks I see some potential Java heap issues
<ul>
<li>Indeed, I see two out of memory errors in Tomcat’s journal:</li>
</ul>
</li>
</ul>
<divclass="highlight"><pretabindex="0"style="color:#f8f8f2;background-color:#272822;-moz-tab-size:4;-o-tab-size:4;tab-size:4;"><codeclass="language-console"data-lang="console"><spanstyle="display:flex;"><span>tomcat7[310996]: java.lang.OutOfMemoryError: Java heap space
</span></span><spanstyle="display:flex;"><span>tomcat7[310996]: Jan 18, 2023 1:37:03 PM org.apache.tomcat.jdbc.pool.ConnectionPool abandon
</span></span></code></pre></div><ul>
<li>Which explains why the locks went down to normal numbers as I was watching… (because Java crashed)</li>
</ul>
<h2id="2023-01-19">2023-01-19</h2>
<ul>
<li>Update a bunch of ORCID identifiers, Initiative mappings, and regions on CGSpace</li>
<li>So it seems an IFPRI user got caught up in the blocking I did yesterday
<ul>
<li>Their ISP is Comcast…</li>
<li>I need to re-work the ASN blocking on nginx, but for now I will just get the ASNs again minus Comcast:</li>
<li>A lot of work on CGSpace metadata (ORCID identifiers, regions, and Initiatives)</li>
<li>I noticed that MEL and CGSpace are using slightly different vocabularies for SDGs so I sent an email to Salem and Sara</li>
</ul>
<h2id="2023-01-21">2023-01-21</h2>
<ul>
<li>Export the Initiatives community again to perform collection mappings and country/region fixes</li>
</ul>
<h2id="2023-01-22">2023-01-22</h2>
<ul>
<li>There has been a high load on the server for a few days, currently 8.0… and I’ve been seeing some PostgreSQL locks stuck all day:</li>
</ul>
<divclass="highlight"><pretabindex="0"style="color:#f8f8f2;background-color:#272822;-moz-tab-size:4;-o-tab-size:4;tab-size:4;"><codeclass="language-console"data-lang="console"><spanstyle="display:flex;"><span>$ psql -c <spanstyle="color:#e6db74">'SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid;'</span> | grep -o -E <spanstyle="color:#e6db74">'(dspaceWeb|dspaceApi|dspaceCli)'</span> | sort | uniq -c
<li>Looking at the locks I see they are from this morning at 5:00 AM, which is the <code>dspace checker-email</code> script
<ul>
<li>Last week I disabled the one that ones at 4:00 AM, but I guess I will experiment with disabling this too…</li>
<li>Then I killed the PIDs of the locks</li>
</ul>
</li>
</ul>
<divclass="highlight"><pretabindex="0"style="color:#f8f8f2;background-color:#272822;-moz-tab-size:4;-o-tab-size:4;tab-size:4;"><codeclass="language-console"data-lang="console"><spanstyle="display:flex;"><span>$ psql -c <spanstyle="color:#e6db74">"SELECT * FROM pg_locks pl LEFT JOIN pg_stat_activity psa ON pl.pid = psa.pid WHERE application_name='dspaceCli';"</span> | less -S
<li>Also, I checked the age of the locks and killed anything over 1 day:</li>
</ul>
<divclass="highlight"><pretabindex="0"style="color:#f8f8f2;background-color:#272822;-moz-tab-size:4;-o-tab-size:4;tab-size:4;"><codeclass="language-console"data-lang="console"><spanstyle="display:flex;"><span>$ psql < locks-age.sql | grep days | less -S
</span></span></code></pre></div><ul>
<li>Then I ran all updates on the server and restarted it…</li>
<li>Salem responded to my question about the SDG mismatch between MEL and CGSpace
<ul>
<li>We agreed to use a version based on the text of <ahref="http://metadata.un.org/sdg/?lang=en">this site</a></li>
</ul>
</li>
<li>Salem is having issues with some REST API submission / updates
<ul>
<li>I updated DSpace Test with a recent CGSpace backup and created a super admin user for him to test</li>
</ul>
</li>
<li>Clean and normalize fifty-eight IFPRI records for batch import to CGSpace
<ul>
<li>I did a duplicate check and found six, so that’s good!</li>
</ul>
</li>
<li>I exported the entire CGSpace to check for missing Initiative mappings
<ul>
<li>Then I exported the Initiatives community to check for missing regions</li>
<li>Then I ran the script to check for missing ORCID identifiers</li>
<li>Then <em>finally</em>, I started a harvest on AReS</li>
<li>Salem found that you can actually harvest everything in DSpace 7 using the <ahref="https://dspace7test.ilri.org/server/api/discover/browses/title/items?page=1&size=100"><code>discover/browses</code> endpoint</a></li>
<li>Exported CGSpace again to examine and clean up a bunch of stuff like ISBNs in the ISSN field, DOIs in the URL field, dataset URLs in the DOI field, normalized a bunch of publisher places, fixed some countries and regions, fixed some licenses, etc
<ul>
<li>I noticed that we still have “North America” as a region, but according to UN M.49 that is the continent, which comprises “Northern America” the region, so I will update our controlled vocabularies and all existing entries</li>
<li>I imported changes to 1,800 items</li>
<li>When it finished five hours later I started a harvest on AReS</li>
</ul>
</li>
</ul>
<h2id="2023-01-24">2023-01-24</h2>
<ul>
<li>Proof and upload seven items for the Rethinking Food Markets Initiative for IFPRI</li>
<li>Export CGSpace to do some minor cleanups, Initiative collection mappings, and region fixes
<ul>
<li>I also added “CGIAR Trust Fund” to all items with an Initiative in <code>cg.contributor.initiative</code></li>
</ul>
</li>
</ul>
<h2id="2023-01-25">2023-01-25</h2>
<ul>
<li>Oh shit, the import last night ran for twelve hours and then died:</li>
</ul>
<divclass="highlight"><pretabindex="0"style="color:#f8f8f2;background-color:#272822;-moz-tab-size:4;-o-tab-size:4;tab-size:4;"><codeclass="language-console"data-lang="console"><spanstyle="display:flex;"><span>Error committing changes to database: could not execute statement
</span></span><spanstyle="display:flex;"><span>Aborting most recent changes.
</span></span></code></pre></div><ul>
<li>I re-submitted a smaller version without the CGIAR Trust Fund changes for now just so we get the regions and other fixes</li>
<li>Do some work on SAPLING issues for CGSpace, sending a large list of issues we found to the MEL team for items they submitted</li>
<li>Abenet noticed that the number of items in the Initiatives community appears to have dropped by about 2,000 in the XMLUI
<ul>
<li>We looked on AReS and all the items are still there</li>
<li>I looked in the DSpace log and see around 2,000 messages like this:</li>
</ul>
</li>
</ul>
<divclass="highlight"><pretabindex="0"style="color:#f8f8f2;background-color:#272822;-moz-tab-size:4;-o-tab-size:4;tab-size:4;"><codeclass="language-console"data-lang="console"><spanstyle="display:flex;"><span>2023-01-25 07:14:59,529 ERROR com.atmire.versioning.ModificationLogger @ Error while writing item to versioning index: c9fac1f2-6b2b-4941-8077-40b7b5c936b6 message:missing required field: epersonID
</span></span><spanstyle="display:flex;"><span> at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:552)
</span></span><spanstyle="display:flex;"><span> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
</span></span><spanstyle="display:flex;"><span> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
</span></span><spanstyle="display:flex;"><span> at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:124)
</span></span><spanstyle="display:flex;"><span> at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
</span></span><spanstyle="display:flex;"><span> at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
</span></span><spanstyle="display:flex;"><span> at com.atmire.versioning.ModificationLogger.indexItem(ModificationLogger.java:263)
</span></span><spanstyle="display:flex;"><span> at com.atmire.versioning.ModificationConsumer.end(ModificationConsumer.java:134)
</span></span><spanstyle="display:flex;"><span> at org.dspace.event.BasicDispatcher.dispatch(BasicDispatcher.java:157)
</span></span><spanstyle="display:flex;"><span> at org.dspace.core.Context.dispatchEvents(Context.java:455)
</span></span><spanstyle="display:flex;"><span> at org.dspace.core.Context.commit(Context.java:424)
</span></span><spanstyle="display:flex;"><span> at org.dspace.core.Context.complete(Context.java:380)
</span></span><spanstyle="display:flex;"><span> at org.dspace.app.bulkedit.MetadataImport.main(MetadataImport.java:1399)
</span></span><spanstyle="display:flex;"><span> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
</span></span><spanstyle="display:flex;"><span> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
</span></span><spanstyle="display:flex;"><span> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
</span></span><spanstyle="display:flex;"><span> at java.lang.reflect.Method.invoke(Method.java:498)
</span></span><spanstyle="display:flex;"><span> at org.dspace.app.launcher.ScriptLauncher.runOneCommand(ScriptLauncher.java:229)
</span></span><spanstyle="display:flex;"><span> at org.dspace.app.launcher.ScriptLauncher.main(ScriptLauncher.java:81)
</span></span></code></pre></div><ul>
<li>I filed a ticket with Atmire to ask them</li>
<li>For now I just did a light Discovery reindex (not the full one) and all the items appeared again</li>
<li>Submit an issue to MEL GitHub regarding the capitalization of CRPs: <ahref="https://github.com/CodeObia/MEL/issues/11133">https://github.com/CodeObia/MEL/issues/11133</a>
<ul>
<li>I talked to Salem and he said that this is a legacy thing from when CGSpace was using ALL CAPS for most of its metadata. I provided him with <ahref="https://ilri.github.io/cgspace-submission-guidelines/cg-contributor-crp/cg-contributor-crp.txt">our current controlled vocabulary for CRPs</a> and he will update it in MEL.</li>
<li>On that note, Peter and Abenet and I realized that we still have an old field <code>cg.subject.crp</code> with about 450 values in it, but it has not been used for a few years (they are using the old ALL CAPS CRPs)</li>
<li>I exported this list of values to lowercase them and move them to <code>cg.contributor.crp</code></li>
<li>Even if some items end up with multiple CRPs, they will get de-duplicated when I remove duplicate values soon</li>
<li>After fixing and moving them all, I deleted the <code>cg.subject.crp</code> field from the metadata registry</li>
<li>I realized a smarter way to update the text lang attributes of metadata would be to restrict the query to items that are in the archive and not withdrawn:</li>
<p>I tried that in a transaction and it hung, so I canceled it and rolled back</p>
</li>
<li>
<p>I see some PostgreSQL locks attributed to <code>dspaceApi</code> that were started at <code>2023-01-25 13:40:04.529087+01</code> and haven’t changed since then (that’s eight hours ago)</p>
<ul>
<li>I killed the pid…</li>
<li>There were also saw some locks owned by <code>dspaceWeb</code> that were nine and four hours old, so I killed those too…</li>
<li>Now Maria was able to archive one submission of hers that was hanging all afternoon, but I still can’t run the update on the text langs…</li>
</ul>
</li>
<li>
<p>Export entire CGSpace to do Initiative mappings again</p>
</li>
<li>
<p>Started a harvest on AReS</p>
</li>
</ul>
<h2id="2023-01-26">2023-01-26</h2>
<ul>
<li>Export entire CGSpace to do some metadata cleanup on various fields
<ul>
<li>I also added “CGIAR Trust Fund” to all items in the Initiatives community</li>
</ul>
</li>
</ul>
<h2id="2023-01-27">2023-01-27</h2>
<ul>
<li>Export a list of affiliations in the Initiatives community for Peter, trying a new method to avoid exporting <em>everything</em> from PostgreSQL:</li>
</span></span><spanstyle="display:flex;"><span> 309 International Center for Agricultural Research in the Dry Areas
</span></span><spanstyle="display:flex;"><span> 412 International Livestock Research Institute
</span></span></code></pre></div><ul>
<li>The second sed command adds the CSV header and quotes back</li>
<li>I did the same for authors and donors and send them to Peter to make corrections</li>
</ul>
<h2id="2023-01-28">2023-01-28</h2>
<ul>
<li>Daniel from the Alliance said they are getting an HTTP 401 when trying to submit items to CGSpace via the REST API</li>
</ul>
<h2id="2023-01-29">2023-01-29</h2>
<ul>
<li>Export the entire CGSpace to do Initiatives collection mappings</li>
<li>I was thinking about a way to use Crossref’s API to enrich our data, for example checking registered DOIs for license information, publishers, etc
<ul>
<li>Turns out I had already written <code>crossref-doi-lookup.py</code> last year, and it works</li>
<li>I exported a list of all DOIs without licenses from CGSpace, minus the CIFOR ones because I know they aren’t registered on Crossref, which is about 11,800 DOIs</li>
<li>The above was done with just 5,000 DOIs because it was taking a long time, but after the last step I imported into OpenRefine to clean up the license URLs
<ul>
<li>Then I imported 635 new licenses to CGSpace woooo</li>
<li>After checking the remaining 6,500 DOIs there were another 852 new licenses, woooo</li>