Open bbpennel opened 2 weeks ago
From the backtrace, it seems that @value
may not be a string, and is frozen already.
Please try using the feature/URI-frozen-bug branch to see if that makes a difference.
Another place that could be tried is in the URI#freeze
implementation to use @value = value.to_s.dup.freeze
, but it really should already be a string at this point.
Unfortunately I can't test it directly since our servers are stuck on ruby 2.7 for a few more months at least. I may be able to monkey patch the one line change in though, I'll look into it.
I can create a branch off of an earlier release that supports 2.7, if that would help.
Try branch 3.2.11-patch, which is based on 3.2.11 with the small change to URI.intern
. It will fail tests because dependencies are all updated, but should run on Ruby 2.7.
Okay, thanks, I'll try that out. It might be a little while before I know whether it resolves the issue, since it's an intermittent issue
We ran another bulk ingest today with the branch deployed and got 2 FrozenErrors. The first one triggered in a different location than usual, while the second one looks similar to the previous error, at least from the perspective of the RDF gem. In all cases the jobs were executed by sidekiq:
2024-07-16 08:38:37 -0400 - ERROR: [ActiveJob] [CreateDerivativesJob] [e026fbc5-09ce-4aec-8723-e86e0681c722] Error performing CreateDerivativesJob (Job ID: e026fbc5-09ce-4aec-8723-e86e0681c722) from Sidekiq(derivatives) in 10373.93ms: FrozenError (can't modify frozen RDF::URI: #<RDF::URI:0xb1044 URI:http://projecthydra.org/ns/auth/acl#>):
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/util/cache.rb:88:in `define_finalizer'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/util/cache.rb:88:in `[]='
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/model/uri.rb:163:in `intern'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:187:in `process_iri'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:294:in `block (2 levels) in read_directive'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:559:in `prod'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:287:in `block in read_directive'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:559:in `prod'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:265:in `read_directive'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:249:in `block in read_statement'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:559:in `prod'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:245:in `read_statement'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:136:in `each_statement'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/model/graph.rb:322:in `block in insert_statements'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/enumerable.rb:183:in `each'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/enumerable.rb:183:in `each'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/enumerable.rb:183:in `each_statement'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/writable.rb:129:in `insert_statements'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/writable.rb:64:in `block in insert'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/util/coercions.rb:38:in `block in coerce_statements'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/util/coercions.rb:35:in `map'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/util/coercions.rb:35:in `coerce_statements'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/writable.rb:64:in `insert'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/mutable.rb:96:in `insert'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/model/graph.rb:328:in `insert_statements'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/writable.rb:86:in `insert_reader'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/writable.rb:29:in `<<'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/mutable.rb:72:in `<<'
/ruby/2.7.0/gems/ldp-1.0.3/lib/ldp/response.rb:108:in `graph'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/ldp_resource.rb:27:in `response_as_graph'
/ruby/2.7.0/gems/ldp-1.0.3/lib/ldp/resource/rdf_source.rb:58:in `response_graph'
/ruby/2.7.0/gems/ldp-1.0.3/lib/ldp/resource/rdf_source.rb:33:in `graph'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/with_metadata/metadata_node.rb:16:in `initialize'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/file.rb:106:in `new'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/file.rb:106:in `metadata'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/file.rb:162:in `block in create_or_update'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/file.rb:161:in `tap'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/file.rb:161:in `create_or_update'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/with_metadata.rb:22:in `create_or_update'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/persistence.rb:44:in `save!'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/associations/contains_association.rb:7:in `insert_record'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/associations/directly_contains_association.rb:6:in `insert_record'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/autosave_association.rb:288:in `block in save_collection_association'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/autosave_association.rb:277:in `each'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/autosave_association.rb:277:in `save_collection_association'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/autosave_association.rb:135:in `block in define_autosave_association_callbacks'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/autosave_association.rb:105:in `instance_eval'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/autosave_association.rb:105:in `block in define_non_cyclic_method'
...
2024-07-16 08:48:47 -0400 - ERROR: [ActiveJob] [CreateDerivativesJob] [eb0741ee-598d-4908-8254-01b091a96a32] Error performing CreateDerivativesJob (Job ID: eb0741ee-598d-4908-8254-01b091a96a32) from Sidekiq(derivatives) in 10635.39ms: FrozenError (can't modify frozen RDF::URI: #<RDF::URI:0xf72b0 URI:http://schema.org/>):
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/model/uri.rb:723:in `block in freeze'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/model/uri.rb:720:in `synchronize'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/model/uri.rb:720:in `freeze'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/model/uri.rb:163:in `intern'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:187:in `process_iri'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:294:in `block (2 levels) in read_directive'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:559:in `prod'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:287:in `block in read_directive'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:559:in `prod'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:265:in `read_directive'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:249:in `block in read_statement'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:559:in `prod'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:245:in `read_statement'
/ruby/2.7.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:136:in `each_statement'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/model/graph.rb:322:in `block in insert_statements'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/enumerable.rb:183:in `each'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/enumerable.rb:183:in `each'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/enumerable.rb:183:in `each_statement'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/writable.rb:129:in `insert_statements'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/writable.rb:64:in `block in insert'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/util/coercions.rb:38:in `block in coerce_statements'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/util/coercions.rb:35:in `map'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/util/coercions.rb:35:in `coerce_statements'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/writable.rb:64:in `insert'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/mutable.rb:96:in `insert'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/model/graph.rb:328:in `insert_statements'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/writable.rb:86:in `insert_reader'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/writable.rb:29:in `<<'
/ruby/2.7.0/bundler/gems/rdf-01cd7b6fc15a/lib/rdf/mixin/mutable.rb:72:in `<<'
/ruby/2.7.0/gems/ldp-1.0.3/lib/ldp/response.rb:108:in `graph'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/ldp_resource.rb:27:in `response_as_graph'
/ruby/2.7.0/gems/ldp-1.0.3/lib/ldp/resource/rdf_source.rb:58:in `response_graph'
/ruby/2.7.0/gems/ldp-1.0.3/lib/ldp/resource/rdf_source.rb:33:in `graph'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/with_metadata/metadata_node.rb:16:in `initialize'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/with_metadata.rb:18:in `new'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/with_metadata.rb:18:in `metadata_node'
...
Might be easier for you to experiment with some changes in a local copy of RDF.rb.
I don't really understand what's going on in the first trace. It seems like something with ObjectCache interaction may be involved.
A change was made in https://github.com/ruby-rdf/rdf/commit/58d8c527387a236418d1f2b1b548c18bcbabd900 to address a memory leak; it's hard to see what the difference could be, but you might try reverting that particular commit.
You could also try modifying RDF::Util::Cache.new to ensure that WeakRefCache cache is used instead of ObjectSpaceCache.
For the second trace, the problem could be in RDF::URI#freeze where the mutex is grabbed after checking to see if it is frozen, which looks like a race condition. Try enclosing the entire method in @mutex.synchronize
:
def freeze
@mutex.synchronize do
unless frozen?
# Create derived components
authority; userinfo; user; password; host; port
@value = value.freeze
@object = object.freeze
@hash = hash.freeze
super
end
end
self
end
I'd start with the change to URI#freeze to see if that handles it.
Sure, I will try some changes. The update to the freeze method makes sense, since if two threads called freeze at the same time, they could both potentially get past the frozen?
check before one of them gets the lock, and then the second one would attempt to freeze again after the first call released the mutex.
Regarding the Cache error, its possible fix freeze
method might fix it as well, since there may be an implicit freeze happening when when define_finalizer
is called. On the other hand, I get the impression that ObjectSpace (and the ObjectSpaceCache) is not necessarily thread safe, so I wonder if using a mutex in there during all the update/delete/finalize operations might be necessary too. Do you think that would make sense?
It might make sense, but let’s start with the URI#freeze? Change to see if that does it. But, of course, it’s up to you.
We have been running into periodic FrozenErrors originating from ruby rdf during periods of concurrent activity in our samvera based application. I have spoken to two other institutions that have been running into the same error.
The error appears to have started when upgrading from 3.2.9 to 3.3.0 in one case, while my own insitution and the other are experiencing it in 3.2.11. I don't see the error happening in our logs prior to upgrading to this version. So it seems as though the issue may have been introduced between 3.2.9 and 3.2.11: https://github.com/ruby-rdf/rdf/compare/3.2.9...3.2.11
Based on the change set and the error's inconsistent nature, I wonder if it could be related to the fix that causes the cache to get cleared out during garbage collection, so entries would potentially need to get repopulated now and could collide. I wonder if that component needs protections to ensure thread safety? But this is just a guess. I may try downgrading to 3.2.9 next.
I had hoped to be able to share a test for reproducing the error, but my attempts so far haven't been successful. The error continues to occur almost every time we do a bulk ingest into our production system, though.
These are the related issues: https://github.com/samvera/bulkrax/issues/947 https://github.com/pulibrary/figgy/issues/6391 https://github.com/avalonmediasystem/avalon/issues/5783