Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

FrozenError during concurrent activity in 3.2.11 #445

Closed
bbpennel opened this issue Jul 8, 2024 · 14 comments
Closed

FrozenError during concurrent activity in 3.2.11 #445

bbpennel opened this issue Jul 8, 2024 · 14 comments
Assignees
Labels

Comments

@bbpennel
Copy link

bbpennel commented Jul 8, 2024

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:
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:
samvera/bulkrax#947
pulibrary/figgy#6391
avalonmediasystem/avalon#5783

FrozenError (can't modify frozen RDF::URI: #<RDF::URI:0xaab40 URI:http://schema.org/>)
FrozenError (can't modify frozen RDF::URI: #<RDF::URI:0x10ece4 URI:http://sweet.jpl.nasa.gov/2.2/reprDataFormat.owl#>)
FrozenError (can't modify frozen RDF::URI: #<RDF::URI:0x89bac URI:http://vocabulary.samvera.org/ns#>)
FrozenError (can't modify frozen RDF::URI: #<RDF::URI:0xc5454 URI:http://www.w3.org/2001/XMLSchema>)
FrozenError (can't modify frozen RDF::URI: #<RDF::URI:0xecd9c URI:http://www.loc.gov/premis/rdf/v3/>)
FrozenError (can't modify frozen RDF::URI: #<RDF::URI:0xd0840 URI:http://www.w3.org/2000/xmlns/>)

FrozenError: can't modify frozen RDF::URI: #<RDF::URI:0x19858f7c URI:http://fedora.info/definitions/v4/config#>
FrozenError: can't modify frozen RDF::URI: #<RDF::URI:0x195f0564 URI:http://avalonmediasystem.org/rdf/vocab/encoding#>
FrozenError: can't modify frozen RDF::URI: #<RDF::URI:0xae8ee99c URI:http://avalonmediasystem.org/rdf/vocab/transcoding#>
FrozenError: can't modify frozen RDF::URI: #<RDF::URI:0x5e0f42b4 URI:http://avalonmediasystem.org/rdf/vocab/media_object#>
2024-02-14 08:38:00 -0500 - ERROR: [ActiveJob] [AttachFilesToWorkJob] [ff4797c5-edef-497d-b3c0-0cda6048cad8] Error performing AttachFilesToWorkJob (Job ID: ff4797c5-edef-497d-b3c0-0cda6048cad8) from Sidekiq(default) in 7736.34ms: FrozenError (can't modify frozen RDF::URI: #<RDF::URI:0xaab40 URI:http://schema.org/>):
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/model/uri.rb:723:in `block in freeze'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/model/uri.rb:720:in `synchronize'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/model/uri.rb:720:in `freeze'
/ruby/2.7.0/gems/rdf-3.2.11/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/gems/rdf-3.2.11/lib/rdf/model/graph.rb:322:in `block in insert_statements'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/mixin/enumerable.rb:183:in `each'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/mixin/enumerable.rb:183:in `each'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/mixin/enumerable.rb:183:in `each_statement'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/mixin/writable.rb:129:in `insert_statements'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/mixin/writable.rb:64:in `block in insert'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/util/coercions.rb:38:in `block in coerce_statements'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/util/coercions.rb:35:in `map'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/util/coercions.rb:35:in `coerce_statements'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/mixin/writable.rb:64:in `insert'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/mixin/mutable.rb:96:in `insert'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/model/graph.rb:328:in `insert_statements'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/mixin/writable.rb:86:in `insert_reader'
/ruby/2.7.0/gems/rdf-3.2.11/lib/rdf/mixin/writable.rb:29:in `<<'
/ruby/2.7.0/gems/rdf-3.2.11/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/fedora_attributes.rb:46:in `resource'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/fedora_attributes.rb:13:in `get_values'
/ruby/2.7.0/gems/active-triples-1.2.0/lib/active_triples/property_builder.rb:70:in `create_date'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/fedora_attributes.rb:20:in `create_date'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/indexing_service.rb:50:in `c_time'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/indexing_service.rb:35:in `generate_solr_document'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/services/hyrax/indexes_thumbnails.rb:15:in `generate_solr_document'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/indexers/hyrax/file_set_indexer.rb:9:in `generate_solr_document'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/indexing.rb:42:in `to_solr'
/ruby/2.7.0/gems/hydra-access-controls-12.1.0/app/models/concerns/hydra/access_controls/permissions.rb:29:in `to_solr'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/models/concerns/hyrax/human_readable_type.rb:17:in `to_solr'
/ruby/2.7.0/gems/hydra-access-controls-12.1.0/app/models/concerns/hydra/access_controls/embargoable.rb:37:in `to_solr'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/indexing.rb:52:in `update_index'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/callbacks.rb:235:in `block in update_index'
/ruby/2.7.0/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:98:in `run_callbacks'
/ruby/2.7.0/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:824:in `_run_update_index_callbacks'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/callbacks.rb:235:in `update_index'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/indexing.rb:82:in `_update_record'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/callbacks.rb:249:in `block in _update_record'
/ruby/2.7.0/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:106:in `run_callbacks'
/ruby/2.7.0/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:824:in `_run_update_callbacks'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/callbacks.rb:249:in `_update_record'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/persistence.rb:179:in `create_or_update'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/callbacks.rb:241:in `block in create_or_update'
/ruby/2.7.0/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:106:in `run_callbacks'
/ruby/2.7.0/gems/activesupport-6.1.7.6/lib/active_support/callbacks.rb:824:in `_run_save_callbacks'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/callbacks.rb:241: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/validations.rb:56:in `save!'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/associations/builder/orders.rb:50:in `save!'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/associations/indirectly_contains_association.rb:16:in `insert_record'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/associations/collection_association.rb:163:in `block (2 levels) in concat_records'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/associations/collection_association.rb:262:in `add_to_target'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/associations/collection_association.rb:162:in `block in concat_records'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/associations/collection_association.rb:160:in `each'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/associations/collection_association.rb:160:in `concat_records'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/associations/indirectly_contains_association.rb:10:in `concat'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/associations/orders_association.rb:55:in `append_target'
/ruby/2.7.0/gems/active-fedora-14.0.1/lib/active_fedora/orders/target_proxy.rb:11:in `<<'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/actors/hyrax/actors/file_set_actor.rb:75:in `block in attach_to_work'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/services/hyrax/lock_manager.rb:25:in `block (2 levels) in lock'
/ruby/2.7.0/gems/redlock-1.3.2/lib/redlock/client.rb:81:in `lock'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/services/hyrax/lock_manager.rb:23:in `block in lock'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/services/hyrax/lock_manager.rb:22:in `then'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/services/hyrax/lock_manager.rb:22:in `lock'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/services/hyrax/lockable.rb:7:in `acquire_lock_for'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/actors/hyrax/actors/file_set_actor.rb:71:in `attach_to_work'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/jobs/attach_files_to_work_job.rb:40:in `attach_work'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/jobs/attach_files_to_work_job.rb:28:in `block in perform_af'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/jobs/attach_files_to_work_job.rb:26:in `each'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/jobs/attach_files_to_work_job.rb:26:in `perform_af'
/ruby/2.7.0/bundler/gems/hyrax-6127e4878a83/app/jobs/attach_files_to_work_job.rb:11:in `perform'
@gkellogg
Copy link
Member

gkellogg commented Jul 8, 2024

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.

@gkellogg gkellogg added the bug label Jul 8, 2024
@gkellogg gkellogg self-assigned this Jul 8, 2024
@bbpennel
Copy link
Author

bbpennel commented Jul 9, 2024

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.

@gkellogg
Copy link
Member

gkellogg commented Jul 9, 2024

I can create a branch off of an earlier release that supports 2.7, if that would help.

@gkellogg
Copy link
Member

gkellogg commented Jul 9, 2024

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.

@bbpennel
Copy link
Author

bbpennel commented Jul 9, 2024

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

@bbpennel
Copy link
Author

bbpennel commented Jul 16, 2024

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'
...

@gkellogg
Copy link
Member

gkellogg commented Jul 17, 2024

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 58d8c52 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.

@bbpennel
Copy link
Author

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?

@gkellogg
Copy link
Member

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.

@gkellogg
Copy link
Member

gkellogg commented Aug 3, 2024

@bbpennel Any update on this? If the fix to RDF::URI does it, I can release a patch and merge the change into the develop branch.

@bbpennel
Copy link
Author

bbpennel commented Aug 3, 2024

@gkellogg We've run two bulk ingests since deploying this change and have not seen the error. So I can't say definitively that its resolved, but looks good so far, and I think it's a reasonable change to make either way

@gkellogg
Copy link
Member

gkellogg commented Aug 4, 2024

Fixed in 3.2.12 and on develop.

@gkellogg gkellogg closed this as completed Aug 4, 2024
@cjcolvar
Copy link
Contributor

We upgraded to rdf 3.2.12 but unfortunately that didn't seem to resolve the RDF::URI::FrozenError for us. We're still seeing them occasionally in background jobs run by sidekiq. FWIW It has happened about 200 times out of 800,000 jobs over 2 weeks.

For example:

2024-08-30T15:08:30.344Z pid=572856 tid=dfgfdk WARN: FrozenError: can't modify frozen RDF::URI: #<RDF::URI:0x31732400 URI:http://avalonmediasystem.org/rdf/vocab/encoding#>
2024-08-30T15:08:30.344Z pid=572856 tid=dfgfdk WARN: /srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/util/cache.rb:88:in `define_finalizer'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/util/cache.rb:88:in `[]='
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/model/uri.rb:163:in `intern'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:187:in `process_iri'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:294:in `block (2 levels) in read_directive'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:559:in `prod'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:287:in `block in read_directive'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:559:in `prod'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:265:in `read_directive'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:249:in `block in read_statement'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:559:in `prod'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:245:in `read_statement'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-turtle-3.2.1/lib/rdf/turtle/reader.rb:136:in `each_statement'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/model/graph.rb:322:in `block in insert_statements'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/mixin/enumerable.rb:183:in `each'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/mixin/enumerable.rb:183:in `each'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/mixin/enumerable.rb:183:in `each_statement'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/mixin/writable.rb:129:in `insert_statements'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/mixin/writable.rb:64:in `block in insert'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/util/coercions.rb:38:in `block in coerce_statements'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/util/coercions.rb:35:in `map'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/util/coercions.rb:35:in `coerce_statements'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/mixin/writable.rb:64:in `insert'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/mixin/mutable.rb:96:in `insert'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/model/graph.rb:328:in `insert_statements'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/mixin/writable.rb:86:in `insert_reader'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/mixin/writable.rb:29:in `<<'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/rdf-3.2.12/lib/rdf/mixin/mutable.rb:72:in `<<'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/ldp-1.1.0/lib/ldp/response.rb:107:in `graph'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/active-fedora-14.0.1/lib/active_fedora/ldp_resource.rb:27:in `response_as_graph'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/ldp-1.1.0/lib/ldp/resource/rdf_source.rb:61:in `response_graph'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/ldp-1.1.0/lib/ldp/resource/rdf_source.rb:36:in `graph'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/active-fedora-14.0.1/lib/active_fedora/default_model_mapper.rb:14:in `classifier'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/active-fedora-14.0.1/lib/active_fedora/relation/finder_methods.rb:192:in `class_to_load'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/active-fedora-14.0.1/lib/active_fedora/relation/finder_methods.rb:181:in `load_from_fedora'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/active-fedora-14.0.1/lib/active_fedora/relation/finder_methods.rb:167:in `find_one'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/active-fedora-14.0.1/lib/active_fedora/relation/finder_methods.rb:212:in `find_with_ids'
/srv/services/avalon_mco_processing-prod-8131/avalon/shared/bundle/ruby/3.2.0/gems/active-fedora-14.0.1/lib/active_fedora/relation/finder_methods.rb:48:in `find'
...

@gkellogg
Copy link
Member

Perhaps your idea about using a mutex in RDF::Util::Cache might solve the issue.

class Cache

  ##
  # @param  [Integer] capacity
  def initialize(capacity = nil)
    @capacity = capacity || RDF.config.cache_size
    @mutex = Mutex.new
    @cache  ||= {}
    @index  ||= {}
  end
end

class ObjectSpaceCache < Cache 
  ##
  # @param  [Object] key
  # @param  [Object] value
  # @return [Object]
  def []=(key, value)
    @mutex.synchronize do
      if capacity?
        id = value.__id__
        @cache[key] = id
        @index[id] = key
        ObjectSpace.define_finalizer(value, finalizer_proc)
      end
    end
    value
  end
end

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants