anlek/mongify

Updating references times out (CURSOR_NOT_FOUND)

Closed this issue · 12 comments

Hi,

I'm migrating a (rather large) MySQL Database to Mongo using Mongify. Things are going well so far, it gets through copying all the tables fine but during the updating of the references for one of the tables (with an ETA of about an hour), about 10-15 mins into this I get the error:

Query response returned CURSOR_NOT_FOUND. Either an invalid cursor was specified, or the cursor may have timed out on the server.

I can see this issue has happened before #80 but mine seems to be in a different context.

I've tried extending the timeout on my SQL local server, and appending the "timeout" parameter to my database.config (which seems to be depreciated as it gives errors).

Are there any ways we get these references to finish? Is mongify appropriate for a large dataset?

Thanks for any help you can give.

anlek commented

Are both your MySQL and MongoDB located on your machine or are they hosted off site?

Both on the same machine

What function does the updating of references do with respect to the new collections?

anlek commented

Not sure. However, the error you reported happens when a timeout from MongoDB is triggered or some odd request happens. I've not seen this before (except for during building of Mongify many years ago). What version of mysql and MongoDB are you using?

MongoDB version v3.2.6.
MySQL version 5.7.12.

Looking at the new collections in the db I'm not sure if the updating references actually does anything so the migration might be okay? I said I'd ask anyway just in case

Just tried again on a more powerful machine, and while it got past updating the references in the collection we had trouble with previously, I got the exact same error on a collection with an ETA of 2 hours.

Maybe I can alter the mongo gem to not timeout after a long time, or do you think there is something in one of the mongify scripts I could change? Again this might not be necessary at all if the references do nothing

Sorry to spam but just to let you know in case you try yourself.

I went into the no_sql_connection.rb script and added the :timeout => false option to the find queries, hoping that it would keep the cursor open after 10 minutes. This is probably a fault on the mongo drivers end, but this didn't work for me at all.

We're going to progress with our project without updating the references as it doesn't seem to be too important in the end.

Hi everyone,

I have the same problem here, but I need to "fix it" in order to use mongify to sync my data between MySQL and MongoDB.

here is the problem:

C:\Users\Vinicius\Desktop>mongify sync database.config translation_file.rb
-- create_table("mongify_sync_helper", {:id=>false})
-> 0.1519s
-- add_index("mongify_sync_helper", :table_name)
-> 0.1162s
Syncing ACT_GE_PROPERTY: (3/3) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:00
Syncing ACT_HI_ACTINST: (18108/18108) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:07:07
Syncing ACT_HI_ATTACHMENT: (0/0) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:00
Syncing ACT_HI_DETAIL: (41908/41908) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:16:44
Syncing ACT_HI_IDENTITYLINK: (2729/2729) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:01:07
Syncing ACT_HI_PROCINST: (1957/1957) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:48
Syncing ACT_HI_TASKINST: (1310/1310) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:32
Syncing ACT_HI_VARINST: (31685/31685) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:12:43
Syncing ACT_RE_DEPLOYMENT: (1451/1451) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:36
Syncing ACT_RE_MODEL: (8/8) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:00
Syncing ACT_RE_PROCDEF: (7645/7645) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:03:06
Syncing ACT_RU_EVENT_SUBSCR: (261/261) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:08
Syncing ACT_RU_EXECUTION: (504/504) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:14
Syncing ACT_RU_IDENTITYLINK: (276/276) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:09
Syncing ACT_RU_JOB: (9/9) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:00
Syncing ACT_RU_TASK: (87/87) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:04
Syncing ACT_RU_VARIABLE: (10124/10124) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:03:40
Setting last_updated_at: (17/17) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:00
Updating References ACT_GE_PROPERTY: (3/3) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:00
Updating References ACT_HI_ACTINST: (18108/18108) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:27:02
Updating References ACT_HI_ATTACHMEN: (0/0) 100% |ooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooooo| Time: 00:00:00
C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongo-1.12.5/lib/mongo/networking.rb:223:in check_response_flags': Query response returned CURSOR_NOT_FOUND. Either an invalid cursor was specified, or the cursor may have timed out on the server. (Mongo::OperationFailure) from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongo-1.12.5/lib/mongo/networking.rb:216:in receive_response_header'
from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongo-1.12.5/lib/mongo/networking.rb:183:in receive' from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongo-1.12.5/lib/mongo/networking.rb:146:in receive_message'
from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongo-1.12.5/lib/mongo/cursor.rb:606:in send_get_more' from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongo-1.12.5/lib/mongo/cursor.rb:534:in refresh'
from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongo-1.12.5/lib/mongo/cursor.rb:139:in next' from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongo-1.12.5/lib/mongo/cursor.rb:342:in each'
from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongify-1.3.1/lib/mongify/translation/sync.rb:86:in block in sync_update_reference_ids' from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongify-1.3.1/lib/mongify/translation/sync.rb:83:in each'
from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongify-1.3.1/lib/mongify/translation/sync.rb:83:in sync_update_reference_ids' from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongify-1.3.1/lib/mongify/translation/sync.rb:32:in sync'
from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongify-1.3.1/lib/mongify/cli/command/worker.rb:75:in execute' from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongify-1.3.1/lib/mongify/cli/application.rb:28:in execute!'
from C:/Ruby23-x64/lib/ruby/gems/2.3.0/gems/mongify-1.3.1/bin/mongify:15:in <top (required)>' from C:/Ruby23-x64/bin/mongify:22:in load'
from C:/Ruby23-x64/bin/mongify:22:in `

'

Sorry to drag this back up - is there a way to set the cursor timeout to false in the mongify config?

A particularly large reference update is where the problem occurred for me (00:51:42).

Mongify version - 1.3.1

Updating References hermes_events:    (11659344/11659344) 100% |oooooooooooooooooooooooooooooooooooooooo| Time: 00:51:42
/Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongo-1.12.5/lib/mongo/networking.rb:223:in `check_response_flags': Query response returned CURSOR_NOT_FOUND. Either an invalid cursor was specified, or the cursor may have timed out on the server. (Mongo::OperationFailure)
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongo-1.12.5/lib/mongo/networking.rb:216:in `receive_response_header'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongo-1.12.5/lib/mongo/networking.rb:183:in `receive'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongo-1.12.5/lib/mongo/networking.rb:146:in `receive_message'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongo-1.12.5/lib/mongo/cursor.rb:606:in `send_get_more'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongo-1.12.5/lib/mongo/cursor.rb:534:in `refresh'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongo-1.12.5/lib/mongo/cursor.rb:139:in `next'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongo-1.12.5/lib/mongo/cursor.rb:342:in `each'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongify-1.3.2/lib/mongify/translation/process.rb:47:in `block in update_reference_ids'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongify-1.3.2/lib/mongify/translation/process.rb:44:in `each'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongify-1.3.2/lib/mongify/translation/process.rb:44:in `update_reference_ids'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongify-1.3.2/lib/mongify/translation/process.rb:15:in `process'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongify-1.3.2/lib/mongify/cli/command/worker.rb:72:in `execute'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongify-1.3.2/lib/mongify/cli/application.rb:28:in `execute!'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/gems/mongify-1.3.2/bin/mongify:17:in `<top (required)>'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/bin/mongify:23:in `load'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/bin/mongify:23:in `<main>'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/bin/ruby_executable_hooks:15:in `eval'
	from /Users/oliverbates/.rvm/gems/ruby-2.4.2/bin/ruby_executable_hooks:15:in `<main>'`
anlek commented

@oscarechobravo Is this a remote MongoDB server you're working on? Or is that how long it takes on a local machine?

I'm having the same problem as @oscarechobravo , in my case it's a local machine

anlek commented

Is it possible that you're running out of RAM and the OS is closing the connection to release the RAM usage?