ServerSelectionTimeoutError after empty response from mongodb

XMLWordPrintableJSON

    • Type: Bug
    • Resolution: Duplicate
    • Priority: Major - P3
    • None
    • Affects Version/s: 3.0.3
    • Component/s: None
    • None
    • None
    • None
    • None
    • None
    • None
    • None
    • None

      After upgrading pymongo from v2.7.2 to v3.0.3 we started getting errors in out django application:

      Traceback (most recent call last):
  File "/opt/venv/lib/python2.7/site-packages/django/core/handlers/base.py", line 111, in get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
  File "/opt/venv/lib/python2.7/site-packages/django/views/decorators/http.py", line 41, in inner
    return func(request, *args, **kwargs)
  File "./tracker/views.py", line 238, in counters
    for document in pydb['event_url_source_all'].find({'site': int(site_id), 'url': url}):
  File "/opt/venv/lib/python2.7/site-packages/pymongo/cursor.py", line 977, in next
    if len(self.__data) or self._refresh():
  File "/opt/venv/lib/python2.7/site-packages/pymongo/cursor.py", line 902, in _refresh
    self.__read_preference))
  File "/opt/venv/lib/python2.7/site-packages/pymongo/cursor.py", line 813, in __send_message
    **kwargs)
  File "/opt/venv/lib/python2.7/site-packages/pymongo/mongo_client.py", line 728, in _send_message_with_response
    server = topology.select_server(selector)
  File "/opt/venv/lib/python2.7/site-packages/pymongo/topology.py", line 121, in select_server
    address))
  File "/opt/venv/lib/python2.7/site-packages/pymongo/topology.py", line 97, in select_servers
    self._error_message(selector))
ServerSelectionTimeoutError: No replica set members found yet

      strace revealed that we are getting this error only when mongodb doesn't return enough data.
      working query:

      sendto(15, "*2\r\n$3\r\nGET\r\n$54\r\n:1:6:counters:0897835589048e427cabb81b38fb66fff8409a95\r\n", 74, 0, NULL, 0) = 74
futex(0x28945a0, FUTEX_WAKE_PRIVATE, 1) = 0
recvfrom(15, "$23\r\n\200\2}q\1X\7\0\0\0twitterq\2K\0s.\r\n", 65536, 0, NULL, NULL) = 30
futex(0x28945a0, FUTEX_WAKE_PRIVATE, 1) = 0

      query generating ServerSelectionTimeoutError exception:

      sendto(16, "*2\r\n$3\r\nGET\r\n$54\r\n:1:6:counters:0897835589048e427cabb81b38fb66fff8409a95\r\n", 74, 0, NULL, 0) = 74
recvfrom(16, "$6\r\n\200\2}q\1.\r\n", 65536, 0, NULL, NULL) = 12
gettimeofday({1441043559, 210954}, NULL) = 0
gettimeofday({1441043559, 211032}, NULL) = 0
futex(0x27f7390, FUTEX_WAKE_PRIVATE, 1) = 1
gettimeofday({1441043559, 211087}, NULL) = 0
select(0, NULL, NULL, NULL, {0, 1000})  = 0 (Timeout)

      Environment:

      mongodb replicaset is configured with 3 nodes: 1 primary, 2 secondary

      $ python -c "import sys; print(sys.version)"
2.7.5 (default, Jun 24 2015, 00:41:19) 
[GCC 4.8.3 20140911 (Red Hat 4.8.3-9)]

      $ python -c "import pymongo; print(pymongo.version); print(pymongo.has_c())"
3.0.3
True

      CentOS Linux release 7.0.1406 (Core)
Django==1.7.7

      uwsgi log:

      *** Starting uWSGI 2.0.8 (64bit) on [Sun Aug 30 03:19:07 2015] ***
compiled with version: 4.8.3 20140911 (Red Hat 4.8.3-9) on 28 August 2015 11:21:52
os: Linux-3.10.0-123.8.1.el7.x86_64 #1 SMP Mon Sep 22 19:06:58 UTC 2014
nodename: app-2118
machine: x86_64
clock source: unix
detected number of CPU cores: 1
current working directory: /
detected binary path: /opt/venv/bin/uwsgi
!!! no internal routing support, rebuild with pcre support !!!
chdir() to /opt/app
your processes number limit is 7699
your memory page size is 4096 bytes
 *** WARNING: you have enabled harakiri without post buffering. Slow upload could be rejected on post-unbuffered webservers *** 
detected max file descriptor number: 1024
lock engine: pthread robust mutexes
thunder lock: enabled
uwsgi socket 0 inherited INET address 127.0.0.1:5001 fd 9
Python version: 2.7.5 (default, Jun 24 2015, 00:41:19)  [GCC 4.8.3 20140911 (Red Hat 4.8.3-9)]
Set PythonHome to /opt/venv
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x1c17c20
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 509320 bytes (497 KB) for 6 cores
*** Operational MODE: preforking ***
WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x1c17c20 pid: 10057 (default app)
*** uWSGI is running in multiple interpreter mode ***
gracefully (RE)spawned uWSGI master process (pid: 10057)
sendmsg(): Transport endpoint is already connected [core/notify.c line 39]
spawned uWSGI worker 1 (pid: 15801, cores: 1)
spawned uWSGI worker 2 (pid: 15802, cores: 1)
spawned uWSGI worker 3 (pid: 15803, cores: 1)
spawned uWSGI worker 4 (pid: 15804, cores: 1)
spawned uWSGI worker 5 (pid: 15805, cores: 1)
spawned uWSGI worker 6 (pid: 15806, cores: 1)

              Assignee:
              Luke Lovett (Inactive)
              Reporter:
              Vitalii Nazg
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

                Created:
                Updated:
                Resolved: