2 Replies Latest reply on Nov 11, 2013 1:14 AM by Hein Boshoff

    IO Connection Timeout results in Empty Redis Master Document

    Hein Boshoff

      RhoConnect: V3.3.6

      Rhodes: V4.0.0

       

      We have a situation where a sync will intermittently fail with Error Code 8 on the client.

       

      The RhoConnect Sync Log reports the following:

      [01:22:03 PM 2013-10-29] SourceAdapter raised query exception: Connection timed out

      [01:22:03 PM 2013-10-29] /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:208:in `rescue in io'

      ...also:

      [01:22:08 PM 2013-10-29] Connection timed out/opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:208:in `rescue in io'

       

      After this error happens, the master document of the specific Source Adapter is empty, although it still reports the document size correctly, e.g. 620.

       

      After this happens, the same error occurs, almost instantly, when syncing that Model (this alludes to the fact that it is not a legitimate timeout).

      The only way to fix this problem is to reset the data on the client and sync again. After successful sync, the master document is filled again.

       

      Please see the full Sync Log below...

      Thank you

      Hein

       

      [01:22:03 PM 2013-10-29] SourceAdapter raised query exception: Connection timed out

      [01:22:03 PM 2013-10-29] /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:208:in `rescue in io'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:206:in `io'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:214:in `read'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:153:in `block (2 levels) in call_pipelined'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:152:in `times'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:152:in `block in call_pipelined'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:187:in `block (2 levels) in process'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:295:in `ensure_connected'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:177:in `block in process'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:256:in `logging'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:176:in `process'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:147:in `call_pipelined'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:121:in `block in call_pipeline'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:243:in `with_reconnect'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:119:in `call_pipeline'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis.rb:2029:in `block in pipelined'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis.rb:36:in `block in synchronize'

      /opt/rhoconnect/lib/ruby/1.9.1/monitor.rb:211:in `mon_synchronize'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis.rb:36:in `synchronize'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis.rb:2025:in `pipelined'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/store.rb:443:in `_delete_doc'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/store.rb:267:in `flash_data'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/document.rb:49:in `flash_data'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_adapter.rb:72:in `block in sync'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/lock_ops.rb:8:in `block in lock'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/store.rb:274:in `lock'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/lock_ops.rb:7:in `lock'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_adapter.rb:71:in `sync'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_adapter.rb:86:in `do_query'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:418:in `_read'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:57:in `read'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:96:in `block (2 levels) in do_query'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/stats/record.rb:54:in `update'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:94:in `block in do_query'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source.rb:287:in `if_need_refresh'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:93:in `do_query'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:87:in `process_query'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/client_sync.rb:38:in `send_cud'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/api/app/query.rb:3:in `block in <top (required)>'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/async.rb:55:in `block (2 levels) in execute_api_call'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/async.rb:41:in `block in catch_all'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/async.rb:41:in `catch'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/async.rb:41:in `catch_all'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/async.rb:54:in `block in execute_api_call'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/eventmachine-1.0.3/lib/eventmachine.rb:1037:in `call'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/eventmachine-1.0.3/lib/eventmachine.rb:1037:in `block in spawn_threadpool'

      [01:22:08 PM 2013-10-29] Connection timed out/opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:208:in `rescue in io'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:206:in `io'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:214:in `read'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:84:in `block in call'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:187:in `block (2 levels) in process'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:295:in `ensure_connected'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:177:in `block in process'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:256:in `logging'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:176:in `process'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis/client.rb:84:in `call'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis.rb:667:in `block in setnx'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis.rb:36:in `block in synchronize'

      /opt/rhoconnect/lib/ruby/1.9.1/monitor.rb:211:in `mon_synchronize'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis.rb:36:in `synchronize'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/redis-3.0.3/lib/redis.rb:666:in `setnx'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/store.rb:284:in `block in get_lock'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/store.rb:283:in `loop'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/store.rb:283:in `get_lock'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/store.rb:273:in `lock'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:428:in `rescue in _read'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:406:in `_read'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:57:in `read'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:96:in `block (2 levels) in do_query'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/stats/record.rb:54:in `update'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:94:in `block in do_query'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source.rb:287:in `if_need_refresh'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:93:in `do_query'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/source_sync.rb:87:in `process_query'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/client_sync.rb:38:in `send_cud'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/api/app/query.rb:3:in `block in <top (required)>'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/async.rb:55:in `block (2 levels) in execute_api_call'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/async.rb:41:in `block in catch_all'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/async.rb:41:in `catch'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/async.rb:41:in `catch_all'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/rhoconnect-3.3.6/lib/rhoconnect/async.rb:54:in `block in execute_api_call'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/eventmachine-1.0.3/lib/eventmachine.rb:1037:in `call'

      /opt/rhoconnect/lib/ruby/gems/1.9.1/gems/eventmachine-1.0.3/lib/eventmachine.rb:1037:in `block in spawn_threadpool'