{"action":"created","issue":{"url":"https://api.github.com/repos/10gen-labs/mongo-connector/issues/244","labels_url":"https://api.github.com/repos/10gen-labs/mongo-connector/issues/244/labels{/name}","comments_url":"https://api.github.com/repos/10gen-labs/mongo-connector/issues/244/comments","events_url":"https://api.github.com/repos/10gen-labs/mongo-connector/issues/244/events","html_url":"https://github.com/10gen-labs/mongo-connector/issues/244","id":70223097,"number":244,"title":"Initial dump no performed with wiredTiger","user":{"login":"heichwald","id":3836175,"avatar_url":"https://avatars.githubusercontent.com/u/3836175?v=3","gravatar_id":"","url":"https://api.github.com/users/heichwald","html_url":"https://github.com/heichwald","followers_url":"https://api.github.com/users/heichwald/followers","following_url":"https://api.github.com/users/heichwald/following{/other_user}","gists_url":"https://api.github.com/users/heichwald/gists{/gist_id}","starred_url":"https://api.github.com/users/heichwald/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/heichwald/subscriptions","organizations_url":"https://api.github.com/users/heichwald/orgs","repos_url":"https://api.github.com/users/heichwald/repos","events_url":"https://api.github.com/users/heichwald/events{/privacy}","received_events_url":"https://api.github.com/users/heichwald/received_events","type":"User","site_admin":false},"labels":[],"state":"closed","locked":false,"assignee":null,"milestone":null,"comments":2,"created_at":"2015-04-22T20:09:11Z","updated_at":"2015-04-22T21:32:56Z","closed_at":"2015-04-22T21:32:56Z","body":"Ok, so this one looks like a tricky one because it does not reproduce for me on all systems:\r\nSo this is not an issue and works properly on my Mac or on Ubuntu (python 2.7) but does not work on my work servers:\r\nCentOS release 6.6 (Final) 64bits\r\npython 2.6.6\r\n\r\nIn all cases (works or not) it was run with: \r\nMongo 3.0.1\r\nMongo-connector 2.0.3\r\n\r\nThe issue only appears with wiredtiger.\r\n\r\nSteps I did were:\r\nDelete the mongo data files in /var/lib/mongo\r\nDelete previous logs and oplog files\r\nStarting mongo -1 node only- and configure it as a replica set with rs.initiate()\r\n\r\n```\r\nsystemLog:\r\n   destination: file\r\n   path: \"/var/log/mongo/mongod.log\"\r\n   logAppend: true\r\n\r\nstorage:\r\n   dbPath: \"/var/lib/mongo\"\r\n   #engine:  mmapv1 \r\n   engine: wiredTiger\r\n   journal:\r\n      enabled: true\r\nprocessManagement:\r\n   fork: true\r\n   pidFilePath: \"/var/run/mongodb/mongod.pid\"\r\nnet:\r\n   bindIp: 0.0.0.0\r\n   port: 27017\r\nreplication:\r\n   replSetName: rs1\r\n\r\n```\r\n\r\n```\r\nrs1:PRIMARY> rs.status()\r\n{\r\n\t\"set\" : \"rs1\",\r\n\t\"date\" : ISODate(\"2015-04-22T20:06:56.171Z\"),\r\n\t\"myState\" : 1,\r\n\t\"members\" : [\r\n\t\t{\r\n\t\t\t\"_id\" : 0,\r\n\t\t\t\"name\" : \"mongo01:27017\",\r\n\t\t\t\"health\" : 1,\r\n\t\t\t\"state\" : 1,\r\n\t\t\t\"stateStr\" : \"PRIMARY\",\r\n\t\t\t\"uptime\" : 4610,\r\n\t\t\t\"optime\" : Timestamp(1429732996, 1),\r\n\t\t\t\"optimeDate\" : ISODate(\"2015-04-22T20:03:16Z\"),\r\n\t\t\t\"electionTime\" : Timestamp(1429728658, 2),\r\n\t\t\t\"electionDate\" : ISODate(\"2015-04-22T18:50:58Z\"),\r\n\t\t\t\"configVersion\" : 1,\r\n\t\t\t\"self\" : true\r\n\t\t}\r\n\t],\r\n\t\"ok\" : 1\r\n}\r\n```\r\n\r\nmongorestore from a dump I took previously\r\nWhen running with mmapv1 engine, mongo-connector runs fine.\r\n\r\nWhen I redo the steps and change the engine, then it looks like mongo-connector does not perform the initial dump and fails -see below-\r\n\r\nAny idea which could cause this behaviour?\r\n\r\nThanks\r\n\r\nCommand to run mongo-connector:\r\n```\r\n/usr/bin/mongo-connector --no-dump false --main mongo01.qa.nymetro.com --verbose 3 --target-url http://elasticsearch01.qa.nymetro.com:9200 --namespace-set assets.images --dest-namespace-set assets_v1.images --doc-manager elastic_doc_manager_nymag  --tz-aware true --logfile /var/log/mongo-connector/log_image_elastic.log --logfile-backups 2 --oplog-ts /var/mongo-connector/oplog_image_elastic.txt > /var/log/mongo-connector/run_image_elastic.log  2>&1 &\r\n```\r\n\r\n```\r\n2015-04-22 15:07:43,278 [INFO] mongo_connector.connector:1001 - Beginning Mongo Connector\r\n2015-04-22 15:07:43,279 [WARNING] mongo_connector.connector:116 - MongoConnector: Can't find /var/mongo-connector/oplog_image_elastic_2015-04-22_15-07-42.txt, attempting to create an empty progress log\r\n2015-04-22 15:07:43,286 [INFO] mongo_connector.connector:223 - MongoConnector: Empty oplog progress file.\r\n2015-04-22 15:07:43,294 [INFO] mongo_connector.oplog_manager:87 - OplogThread: Initializing oplog thread\r\n2015-04-22 15:07:43,297 [INFO] mongo_connector.connector:295 - MongoConnector: Starting connection thread MongoClient('mongo01.qa.nymetro.com', 27017)\r\n2015-04-22 15:07:43,298 [DEBUG] mongo_connector.oplog_manager:154 - OplogThread: Run thread started\r\n2015-04-22 15:07:43,298 [DEBUG] mongo_connector.oplog_manager:156 - OplogThread: Getting cursor\r\n2015-04-22 15:07:43,298 [DEBUG] mongo_connector.oplog_manager:656 - OplogThread: reading last checkpoint as None \r\n2015-04-22 15:07:44,669 [DEBUG] mongo_connector.oplog_manager:568 - OplogThread: Last oplog entry has timestamp 1429729603.\r\n2015-04-22 15:07:44,671 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:07:46,055 [DEBUG] mongo_connector.oplog_manager:174 - OplogThread: Got the cursor, count is 1\r\n2015-04-22 15:07:46,055 [DEBUG] mongo_connector.oplog_manager:181 - OplogThread: about to process new oplog entries\r\n2015-04-22 15:07:46,055 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:07:47,167 [DEBUG] mongo_connector.oplog_manager:190 - OplogThread: Iterating through cursor, document number in this cursor is 0\r\n2015-04-22 15:07:47,168 [DEBUG] mongo_connector.oplog_manager:235 - OplogThread: Operation for this entry is u\r\n2015-04-22 15:07:47,168 [DEBUG] urllib3.util.retry:155 - Converted retries value: False -> Retry(total=False, connect=None, read=None, redirect=0)\r\n2015-04-22 15:07:47,169 [INFO] urllib3.connectionpool:188 - Starting new HTTP connection (1): 172.20.1.68\r\n2015-04-22 15:07:47,187 [DEBUG] urllib3.connectionpool:362 - \"POST /_refresh HTTP/1.1\" 200 51\r\n2015-04-22 15:07:47,187 [INFO] elasticsearch:57 - POST http://172.20.1.68:9200/_refresh [status:200 request:0.019s]\r\n2015-04-22 15:07:47,188 [DEBUG] elasticsearch:59 - > None\r\n2015-04-22 15:07:47,188 [DEBUG] elasticsearch:60 - < {\"_shards\":{\"total\":36,\"successful\":26,\"failed\":0}}\r\n2015-04-22 15:07:47,190 [DEBUG] urllib3.util.retry:155 - Converted retries value: False -> Retry(total=False, connect=None, read=None, redirect=0)\r\n2015-04-22 15:07:47,193 [DEBUG] urllib3.connectionpool:362 - \"GET /assets_v2/images/5214edd5e4b0af2571e32ca3 HTTP/1.1\" 404 86\r\n2015-04-22 15:07:47,194 [WARNING] elasticsearch:76 - GET /assets_v2/images/5214edd5e4b0af2571e32ca3 [status:404 request:0.004s]\r\n2015-04-22 15:07:47,194 [INFO] elasticsearch:84 - > None\r\n2015-04-22 15:07:47,194 [ERROR] mongo_connector.doc_managers.elastic_doc_manager_nymag:186 - Error in update\r\nTraceback (most recent call last):\r\n  File \"/usr/lib/python2.6/site-packages/mongo_connector/doc_managers/elastic_doc_manager_nymag.py\", line 177, in update\r\n    id=u(document_id))\r\n  File \"/usr/lib/python2.6/site-packages/elasticsearch/client/utils.py\", line 68, in _wrapped\r\n    return func(*args, params=params, **kwargs)\r\n  File \"/usr/lib/python2.6/site-packages/elasticsearch/client/__init__.py\", line 272, in get\r\n    params=params)\r\n  File \"/usr/lib/python2.6/site-packages/elasticsearch/transport.py\", line 284, in perform_request\r\n    status, headers, data = connection.perform_request(method, url, params, body, ignore=ignore, timeout=timeout)\r\n  File \"/usr/lib/python2.6/site-packages/elasticsearch/connection/http_urllib3.py\", line 55, in perform_request\r\n    self._raise_error(response.status, raw_data)\r\n  File \"/usr/lib/python2.6/site-packages/elasticsearch/connection/base.py\", line 97, in _raise_error\r\n    raise HTTP_EXCEPTIONS.get(status_code, TransportError)(status_code, error_message, additional_info)\r\nNotFoundError: TransportError(404, u'{\"_index\":\"assets_v2\",\"_type\":\"images\",\"_id\":\"5214edd5e4b0af2571e32ca3\",\"found\":false}')\r\n2015-04-22 15:07:47,196 [DEBUG] mongo_connector.oplog_manager:290 - OplogThread: Doc is processed.\r\n2015-04-22 15:07:52,234 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:07:52,234 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:07:52,236 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:07:57,278 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:07:57,279 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:07:57,281 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:08:02,294 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:08:02,327 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:08:02,328 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:08:07,341 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:08:07,342 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:08:07,345 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:08:12,360 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:08:12,361 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:08:12,363 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:08:17,376 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:08:17,376 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:08:17,377 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:08:22,390 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:08:22,390 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:08:22,390 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:08:27,403 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:08:27,403 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:08:27,403 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:08:32,416 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:08:32,416 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:08:32,417 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:08:37,429 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:08:37,429 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:08:37,431 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:08:42,445 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:08:42,445 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:08:42,447 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:08:47,460 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:08:47,460 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:08:47,462 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n2015-04-22 15:08:52,476 [DEBUG] mongo_connector.oplog_manager:302 - OplogThread: updating checkpoint afterprocessing new oplog entries\r\n2015-04-22 15:08:52,476 [DEBUG] mongo_connector.oplog_manager:642 - OplogThread: oplog checkpoint updated to Timestamp(1429729603, 1)\r\n2015-04-22 15:08:52,478 [DEBUG] mongo_connector.oplog_manager:184 - OplogThread: Cursor is still alive and thread is still running.\r\n```"},"comment":{"url":"https://api.github.com/repos/10gen-labs/mongo-connector/issues/comments/95344185","html_url":"https://github.com/10gen-labs/mongo-connector/issues/244#issuecomment-95344185","issue_url":"https://api.github.com/repos/10gen-labs/mongo-connector/issues/244","id":95344185,"user":{"login":"heichwald","id":3836175,"avatar_url":"https://avatars.githubusercontent.com/u/3836175?v=3","gravatar_id":"","url":"https://api.github.com/users/heichwald","html_url":"https://github.com/heichwald","followers_url":"https://api.github.com/users/heichwald/followers","following_url":"https://api.github.com/users/heichwald/following{/other_user}","gists_url":"https://api.github.com/users/heichwald/gists{/gist_id}","starred_url":"https://api.github.com/users/heichwald/starred{/owner}{/repo}","subscriptions_url":"https://api.github.com/users/heichwald/subscriptions","organizations_url":"https://api.github.com/users/heichwald/orgs","repos_url":"https://api.github.com/users/heichwald/repos","events_url":"https://api.github.com/users/heichwald/events{/privacy}","received_events_url":"https://api.github.com/users/heichwald/received_events","type":"User","site_admin":false},"created_at":"2015-04-22T21:32:56Z","updated_at":"2015-04-22T21:32:56Z","body":"Indeed you are right.\r\nThanks a lot\r\nI close this issue as invalid."}}