RETS gem GetObject request failing inconsistently

Question

I have a long running rake task that updates MLS data every night. The task first updates listing data, then after all the listings are updated, the pictures are loaded via Rails 5.2 activestorage. The listings get updated just fine over a period of 2-4 hours, but the picture loading will run for 10 to 30 minutes before failing with the same Rets::InvalidIdentifier: Got error code 20402 (Invalid Identifier) error.

This error is coming from the MLS Rets server.

I am using the estately/rets gem and using Suckerpunch to run the task asynchronously. The code that results in the error:

line 156                  puts 'Now save the pictures'
    157
    158          ids.each do |id|
    159            p = Listing.find(id)
    160              mlsid = p.mlsid
    161            photos = client.objects '*', {
    162               resource: 'Property',
                   object_type: 'Photo',
                   resource_id: mlsid
                 }
                if photos.count < 1
                  next
                end
                photos.each_with_index do |photo, index|
                  p.images.attach(io: StringIO.new(photo.body), filename: "#{p.mlsid}-#{index}.jpg")
                end
                puts "#{photos.count} images attached to listing_id = #{p.id}"
              end # pictures ids.each do
            client.logout

and the full error trace below:

    I, [2018-06-07T06:26:53.943065 #4]  INFO -- :   S3 Storage (36.8ms) Uploaded file to key: XWoiiTfSh9LR25zKA8y4tpc8 (checksum: oybNBOCMwYTKqaTO5j5Nuw==)
D, [2018-06-07T06:26:53.944271 #4] DEBUG -- :    (1.0ms)  BEGIN
D, [2018-06-07T06:26:53.946751 #4] DEBUG -- :   ActiveStorage::Blob Create (1.4ms)  INSERT INTO "active_storage_blobs" ("key", "filename", "content_type", "metadata", "byte_size", "checksum", "created_at") VALUES ($1, $2, $3, $4, $5, $6, $7) RETURNING "id"  [["key", "XWoiiTfSh9LR25zKA8y4tpc8"], ["filename", "09973750-21.jpg"], ["content_type", "image/jpeg"], ["metadata", "{\"identified\":true}"], ["byte_size", 35097], ["checksum", "oybNBOCMwYTKqaTO5j5Nuw=="], ["created_at", "2018-06-07 06:26:53.944514"]]
D, [2018-06-07T06:26:53.950865 #4] DEBUG -- : [ActiveJob] [ActiveStorage::AnalyzeJob] [e18de7a4-86bb-4075-844d-5466801613d0]    (1.7ms)  BEGIN
D, [2018-06-07T06:26:53.952073 #4] DEBUG -- :    (4.7ms)  COMMIT
D, [2018-06-07T06:26:53.953379 #4] DEBUG -- :    (1.0ms)  BEGIN
D, [2018-06-07T06:26:53.953591 #4] DEBUG -- : [ActiveJob] [ActiveStorage::AnalyzeJob] [e18de7a4-86bb-4075-844d-5466801613d0]   ActiveStorage::Blob Update (1.6ms)  UPDATE "active_storage_blobs" SET "metadata" = $1 WHERE "active_storage_blobs"."id" = $2  [["metadata", "{\"identified\":true,\"width\":180,\"height\":225,\"analyzed\":true}"], ["id", 25654]]
D, [2018-06-07T06:26:53.956386 #4] DEBUG -- :   ActiveStorage::Attachment Create (0.9ms)  INSERT INTO "active_storage_attachments" ("name", "record_type", "record_id", "blob_id", "created_at") VALUES ($1, $2, $3, $4, $5) RETURNING "id"  [["name", "images"], ["record_type", "Listing"], ["record_id", 441544], ["blob_id", 25655], ["created_at", "2018-06-07 06:26:53.954865"]]
D, [2018-06-07T06:26:53.958520 #4] DEBUG -- : [ActiveJob] [ActiveStorage::AnalyzeJob] [e18de7a4-86bb-4075-844d-5466801613d0]    (2.7ms)  COMMIT
D, [2018-06-07T06:26:53.958787 #4] DEBUG -- :   Listing Update (1.3ms)  UPDATE "listings" SET "updated_at" = $1 WHERE "listings"."id" = $2  [["updated_at", "2018-06-07 06:26:53.956749"], ["id", 441544]]
I, [2018-06-07T06:26:53.959030 #4]  INFO -- : [ActiveJob] [ActiveStorage::AnalyzeJob] [e18de7a4-86bb-4075-844d-5466801613d0] Performed ActiveStorage::AnalyzeJob (Job ID: e18de7a4-86bb-4075-844d-5466801613d0) from Async(default) in 47.95ms
D, [2018-06-07T06:26:53.960650 #4] DEBUG -- :    (1.4ms)  COMMIT
I, [2018-06-07T06:26:53.961439 #4]  INFO -- : [ActiveJob] Enqueued ActiveStorage::AnalyzeJob (Job ID: a9027f11-5ec0-4f0a-96f7-ae999a373395) to Async(default) with arguments: #<GlobalID:0x0000000003645a20 @uri=#<URI::GID gid://schoolsparrow/ActiveStorage::Blob/25655>>
22 images attached to listing_id = 441544
D, [2018-06-07T06:26:53.964406 #4] DEBUG -- :   Listing Load (1.4ms)  SELECT  "listings".* FROM "listings" WHERE "listings"."id" = $1 LIMIT $2  [["id", 441545], ["LIMIT", 1]]
D, [2018-06-07T06:26:53.965427 #4] DEBUG -- :   ActiveStorage::Blob Load (1.1ms)  SELECT  "active_storage_blobs".* FROM "active_storage_blobs" WHERE "active_storage_blobs"."id" = $1 LIMIT $2  [["id", 25655], ["LIMIT", 1]]
I, [2018-06-07T06:26:53.966994 #4]  INFO -- : [ActiveJob] [ActiveStorage::AnalyzeJob] [a9027f11-5ec0-4f0a-96f7-ae999a373395] Performing ActiveStorage::AnalyzeJob (Job ID: a9027f11-5ec0-4f0a-96f7-ae999a373395) from Async(default) with arguments: #<GlobalID:0x00000000035480a0 @uri=#<URI::GID gid://schoolsparrow/ActiveStorage::Blob/25655>>
D, [2018-06-07T06:26:54.003064 #4] DEBUG -- : [ActiveJob] [ActiveStorage::AnalyzeJob] [a9027f11-5ec0-4f0a-96f7-ae999a373395]    (0.9ms)  BEGIN
D, [2018-06-07T06:26:54.005782 #4] DEBUG -- : [ActiveJob] [ActiveStorage::AnalyzeJob] [a9027f11-5ec0-4f0a-96f7-ae999a373395]   ActiveStorage::Blob Update (1.3ms)  UPDATE "active_storage_blobs" SET "metadata" = $1 WHERE "active_storage_blobs"."id" = $2  [["metadata", "{\"identified\":true,\"width\":202,\"height\":225,\"analyzed\":true}"], ["id", 25655]]
D, [2018-06-07T06:26:54.012433 #4] DEBUG -- : [ActiveJob] [ActiveStorage::AnalyzeJob] [a9027f11-5ec0-4f0a-96f7-ae999a373395]    (6.0ms)  COMMIT
I, [2018-06-07T06:26:54.012766 #4]  INFO -- : [ActiveJob] [ActiveStorage::AnalyzeJob] [a9027f11-5ec0-4f0a-96f7-ae999a373395] Performed ActiveStorage::AnalyzeJob (Job ID: a9027f11-5ec0-4f0a-96f7-ae999a373395) from Async(default) in 45.53ms
rake aborted!
Rets::InvalidIdentifier: Got error code 20402 (Invalid Identifier)
/app/vendor/bundle/ruby/2.3.0/gems/rets-0.11.0/lib/rets/parser/error_checker.rb:33:in `check'
/app/vendor/bundle/ruby/2.3.0/gems/rets-0.11.0/lib/rets/parser/multipart.rb:35:in `check_for_invalids_parts!'
/app/vendor/bundle/ruby/2.3.0/gems/rets-0.11.0/lib/rets/parser/multipart.rb:29:in `parse'
/app/vendor/bundle/ruby/2.3.0/gems/rets-0.11.0/lib/rets/client.rb:216:in `create_parts_from_response'
/app/vendor/bundle/ruby/2.3.0/gems/rets-0.11.0/lib/rets/client.rb:203:in `objects'
/app/app/jobs/mred_job.rb:162:in `block in perform'
/app/app/jobs/mred_job.rb:159:in `each'
/app/app/jobs/mred_job.rb:159:in `perform'
/app/lib/tasks/update.rake:10:in `update_mred'
/app/lib/tasks/update.rake:6:in `block (2 levels) in <top (required)>'
/app/vendor/bundle/ruby/2.3.0/gems/rake-12.3.1/exe/rake:27:in `<top (required)>'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/lib/bundler/cli/exec.rb:74:in `load'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/lib/bundler/cli/exec.rb:74:in `kernel_load'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/lib/bundler/cli/exec.rb:27:in `run'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/lib/bundler/cli.rb:360:in `exec'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/lib/bundler/vendor/thor/lib/thor/command.rb:27:in `run'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/lib/bundler/vendor/thor/lib/thor/invocation.rb:126:in `invoke_command'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/lib/bundler/vendor/thor/lib/thor.rb:369:in `dispatch'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/lib/bundler/cli.rb:20:in `dispatch'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/lib/bundler/vendor/thor/lib/thor/base.rb:444:in `start'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/lib/bundler/cli.rb:10:in `start'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/exe/bundle:30:in `block in <top (required)>'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/lib/bundler/friendly_errors.rb:121:in `with_friendly_errors'
/app/vendor/bundle/ruby/2.3.0/gems/bundler-1.15.2/exe/bundle:22:in `<top (required)>'
/app/bin/bundle:3:in `load'
/app/bin/bundle:3:in `<main>'
Tasks: TOP => update:mred

Does anyone have an idea about why this is works for a while, then crashes with the same error? Any thoughts would be much appreciated!

score 1 · Accepted Answer · answered Jul 02 '18 at 22:20

I ended up solving this question by adding an error rescue around the RETS query like this:

           begin
            photos = client.objects '*', {
               resource: 'Property',
               object_type: 'Photo',
               resource_id: mlsid
             }
           rescue => e
             puts 'Error: ' + e.message
             next
           end

score 0 · Answer 2 · answered Jun 08 '18 at 08:59

Try changing the request ID. There is a change both Listing ID and Listing Key field will be available for a MLS. Depends on MLS it may take either one, to extract the image.

Please have look into this document. It says,

If the server does not support UID for the requested type of objects and the client submits a UID instead of the ID, the server MUST respond with an error. The preferred error code is 20403: No Object Found. Servers that do not implement the PostObject functionality (Section 13) MAY respond with a 20402: Invalid Identifier. If the requested type of object has an ObjectData class linked in the metadata, the server MUST support this argument

Hope this will help.

RETS gem GetObject request failing inconsistently

2 Answers2