title: MongoDB Cursor Timeout on Update
body: <p>I'm currently writing a PHP script to compile data from a number of different CSVs and import the combined document into Mongo. During this process, I'm running into an error with my cursor timing out during an update. Seen here (with included var_dump() for $line and $voterId):</p>
  <pre><code>PHP Fatal error:  Uncaught exception 'MongoCursorTimeoutException' with message 'localhost:27017: Read timed out after reading 0 bytes, waited for 30.000000 seconds' in /Users/georgeyates/Projects/cerebro-jobs/cavers-parse-phone.php:40
  Stack trace:
  #0 cavers-parse-phone.php(40): MongoCollection-&gt;update(Array, Array)
  #1 {main}
    thrown in cavers-parse-phone.php on line 40
  
  Fatal error: Uncaught exception 'MongoCursorTimeoutException' with message 'localhost:27017: Read timed out after reading 0 bytes, waited for 30.000000 seconds' in /Users/georgeyates/Projects/cerebro-jobs/cavers-parse-phone.php:40
  Stack trace:
  #0 cavers-parse-phone.php(40): MongoCollection-&gt;update(Array, Array)
  #1 {main}
    thrown in cavers-parse-phone.php on line 40
  </code></pre>
  <p>The &quot;Id&quot; field in the search criteria of the update is indexed and finds executed through the Mongo console or PHP are sub-second. Also if I run the update manually through the Mongo console there are no problems and it runs sub-second. Here's my PHP code, $voterId, and $line are both a valid string and array respectively:</p>
  <pre><code>$db-&gt;Voters-&gt;update(array(
      array(
          &quot;Id&quot; =&gt; $voterId
      )
  ),
  array(
      '$push' =&gt; array(
          &quot;PhoneCalls&quot; =&gt; $line
      )
  ));
  </code></pre>
  <p>Currently during development I've got the whole process running locally on my machine. Interestingly enough, when I exit out of the mongod process, I see the query in the log dumped during the exit process which indicates to me that there's a problem with the update. You can see a single server session log from startup to exit with only that single update query running below:</p>
  <pre><code>Tue Jan  7 16:44:53.266 [initandlisten] MongoDB starting : pid=4963 port=27017 dbpath=/usr/local/var/mongodb 64-bit host=Georges-MacBook-Pro.local
  Tue Jan  7 16:44:53.266 [initandlisten] 
  Tue Jan  7 16:44:53.266 [initandlisten] ** WARNING: soft rlimits too low. Number of files is 256, should be at least 1000
  Tue Jan  7 16:44:53.266 [initandlisten] db version v2.4.8
  Tue Jan  7 16:44:53.266 [initandlisten] git version: nogitversion
  Tue Jan  7 16:44:53.266 [initandlisten] build info: Darwin Georges-MacBook-Pro.local 13.0.2 Darwin Kernel Version 13.0.2: Sun Sep 29 19:38:57 PDT 2013; root:xnu-2422.75.4~1/RELEASE_X86_64 x86_64 BOOST_LIB_VERSION=1_49
  Tue Jan  7 16:44:53.266 [initandlisten] allocator: tcmalloc
  Tue Jan  7 16:44:53.266 [initandlisten] options: { bind_ip: &quot;127.0.0.1&quot;, config: &quot;/usr/local/etc/mongod.conf&quot;, dbpath: &quot;/usr/local/var/mongodb&quot;, logappend: &quot;true&quot;, logpath: &quot;/usr/local/var/log/mongodb/mongo.log&quot; }
  Tue Jan  7 16:44:53.268 [initandlisten] journal dir=/usr/local/var/mongodb/journal
  Tue Jan  7 16:44:53.268 [initandlisten] recover : no journal files present, no recovery needed
  Tue Jan  7 16:44:53.474 [websvr] admin web console waiting for connections on port 28017
  Tue Jan  7 16:44:53.474 [initandlisten] waiting for connections on port 27017
  Tue Jan  7 16:45:23.839 [initandlisten] connection accepted from 127.0.0.1:63253 #1 (1 connection now open)
  Tue Jan  7 16:45:57.638 [signalProcessingThread] got signal 2 (Interrupt: 2), will terminate after current cmd ends
  Tue Jan  7 16:45:57.640 [signalProcessingThread] now exiting
  Tue Jan  7 16:45:57.640 dbexit: 
  Tue Jan  7 16:45:57.640 [signalProcessingThread] shutdown: going to close listening sockets...
  Tue Jan  7 16:45:57.640 [signalProcessingThread] closing listening socket: 9
  Tue Jan  7 16:45:57.640 [conn1] update cavers-import.Voters query: { 0: { Id: &quot;a0Qd0000001kMRwEAM&quot; } } update: { $push: { PhoneCalls: [ &quot;a0ed0000000p75wAAA&quot;, &quot;005d00000010pc9AAA&quot;, &quot;0&quot;, &quot;Phone- 000000000&quot;, &quot;2012-09-21 19:16:30&quot;, &quot;005d00000010pc9AAA&quot;, &quot;2012-09-21 19:16:30&quot;, &quot;005d00000010pc9AAA&quot;, &quot;2013-01-05 17:18:54&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;Sample Question Text appears here !&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;0&quot;, &quot;0&quot;, &quot;0&quot;, &quot;0&quot;, &quot;0&quot;, &quot;0&quot;, &quot;0&quot;, &quot;0&quot;, &quot;0&quot;, &quot;0&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;Undecided&quot;, &quot;Undecided&quot;, &quot;Undecided&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;0&quot;, &quot;0&quot;, &quot;0&quot;, &quot;a0Qd0000001kMRwEAM&quot;, &quot;Favorable&quot;, &quot;House 55 &gt; 65, VP3-7&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot;, &quot;&quot; ] } } nscanned:816378 keyUpdates:0 exception: interrupted at shutdown code:11600 numYields: 7907 locks(micros) w:62634071 33653ms
  Tue Jan  7 16:45:57.640 [signalProcessingThread] closing listening socket: 10
  Tue Jan  7 16:45:57.640 [signalProcessingThread] closing listening socket: 11
  Tue Jan  7 16:45:57.640 [signalProcessingThread] removing socket file: /tmp/mongodb-27017.sock
  Tue Jan  7 16:45:57.641 [signalProcessingThread] shutdown: going to flush diaglog...
  Tue Jan  7 16:45:57.641 [signalProcessingThread] shutdown: going to close sockets...
  Tue Jan  7 16:45:57.641 [signalProcessingThread] shutdown: waiting for fs preallocator...
  Tue Jan  7 16:45:57.641 [signalProcessingThread] shutdown: lock for final commit...
  Tue Jan  7 16:45:57.641 [signalProcessingThread] shutdown: final commit...
  Tue Jan  7 16:45:57.953 [signalProcessingThread] shutdown: closing all files...
  Tue Jan  7 16:45:58.024 [signalProcessingThread] closeAllFiles() finished
  Tue Jan  7 16:45:58.024 [signalProcessingThread] journalCleanup...
  Tue Jan  7 16:45:58.024 [signalProcessingThread] removeJournalFiles
  Tue Jan  7 16:45:58.032 [signalProcessingThread] shutdown: removing fs lock...
  Tue Jan  7 16:45:58.032 dbexit: really exiting now
  </code></pre>
  <p>You can see the query dumped in line 19 of that dump.</p>
  <p>Thanks a lot for your time and let me know if there's any more info required.</p>
  <hr />
  <h2>EDIT:</h2>
  <p>As requested, here's a var_dump() for <code>$voterId</code> and <code>$line</code>:</p>
  <p><strong>$voterId</strong></p>
  <pre><code>string(18) &quot;a0Qd0000001kMRwEAM&quot;
  </code></pre>
  <p><strong>$line</strong></p>
  <pre><code>array(95) {
    [0]=&gt;
    string(18) &quot;a0ed0000000p75wAAA&quot;
    [1]=&gt;
    string(18) &quot;005d00000010pc9AAA&quot;
    [2]=&gt;
    string(1) &quot;0&quot;
    [3]=&gt;
    string(16) &quot;Phone- 000000000&quot;
    [4]=&gt;
    string(19) &quot;2012-09-21 19:16:30&quot;
    [5]=&gt;
    string(18) &quot;005d00000010pc9AAA&quot;
    [6]=&gt;
    string(19) &quot;2012-09-21 19:16:30&quot;
    [7]=&gt;
    string(18) &quot;005d00000010pc9AAA&quot;
    [8]=&gt;
    string(19) &quot;2013-01-05 17:18:54&quot;
    [9]=&gt;
    string(0) &quot;&quot;
    [10]=&gt;
    string(0) &quot;&quot;
    [11]=&gt;
    string(0) &quot;&quot;
    [12]=&gt;
    string(35) &quot;Sample Question Text appears here !&quot;
    [13]=&gt;
    string(0) &quot;&quot;
    [14]=&gt;
    string(0) &quot;&quot;
    [15]=&gt;
    string(0) &quot;&quot;
    [16]=&gt;
    string(0) &quot;&quot;
    [17]=&gt;
    string(0) &quot;&quot;
    [18]=&gt;
    string(0) &quot;&quot;
    [19]=&gt;
    string(0) &quot;&quot;
    [20]=&gt;
    string(0) &quot;&quot;
    [21]=&gt;
    string(0) &quot;&quot;
    [22]=&gt;
    string(0) &quot;&quot;
    [23]=&gt;
    string(0) &quot;&quot;
    [24]=&gt;
    string(0) &quot;&quot;
    [25]=&gt;
    string(0) &quot;&quot;
    [26]=&gt;
    string(0) &quot;&quot;
    [27]=&gt;
    string(0) &quot;&quot;
    [28]=&gt;
    string(0) &quot;&quot;
    [29]=&gt;
    string(0) &quot;&quot;
    [30]=&gt;
    string(0) &quot;&quot;
    [31]=&gt;
    string(0) &quot;&quot;
    [32]=&gt;
    string(0) &quot;&quot;
    [33]=&gt;
    string(0) &quot;&quot;
    [34]=&gt;
    string(0) &quot;&quot;
    [35]=&gt;
    string(0) &quot;&quot;
    [36]=&gt;
    string(0) &quot;&quot;
    [37]=&gt;
    string(0) &quot;&quot;
    [38]=&gt;
    string(0) &quot;&quot;
    [39]=&gt;
    string(0) &quot;&quot;
    [40]=&gt;
    string(0) &quot;&quot;
    [41]=&gt;
    string(0) &quot;&quot;
    [42]=&gt;
    string(0) &quot;&quot;
    [43]=&gt;
    string(1) &quot;0&quot;
    [44]=&gt;
    string(1) &quot;0&quot;
    [45]=&gt;
    string(1) &quot;0&quot;
    [46]=&gt;
    string(1) &quot;0&quot;
    [47]=&gt;
    string(1) &quot;0&quot;
    [48]=&gt;
    string(1) &quot;0&quot;
    [49]=&gt;
    string(1) &quot;0&quot;
    [50]=&gt;
    string(1) &quot;0&quot;
    [51]=&gt;
    string(1) &quot;0&quot;
    [52]=&gt;
    string(1) &quot;0&quot;
    [53]=&gt;
    string(0) &quot;&quot;
    [54]=&gt;
    string(0) &quot;&quot;
    [55]=&gt;
    string(0) &quot;&quot;
    [56]=&gt;
    string(9) &quot;Undecided&quot;
    [57]=&gt;
    string(9) &quot;Undecided&quot;
    [58]=&gt;
    string(9) &quot;Undecided&quot;
    [59]=&gt;
    string(0) &quot;&quot;
    [60]=&gt;
    string(0) &quot;&quot;
    [61]=&gt;
    string(0) &quot;&quot;
    [62]=&gt;
    string(0) &quot;&quot;
    [63]=&gt;
    string(0) &quot;&quot;
    [64]=&gt;
    string(0) &quot;&quot;
    [65]=&gt;
    string(0) &quot;&quot;
    [66]=&gt;
    string(0) &quot;&quot;
    [67]=&gt;
    string(0) &quot;&quot;
    [68]=&gt;
    string(0) &quot;&quot;
    [69]=&gt;
    string(0) &quot;&quot;
    [70]=&gt;
    string(0) &quot;&quot;
    [71]=&gt;
    string(0) &quot;&quot;
    [72]=&gt;
    string(0) &quot;&quot;
    [73]=&gt;
    string(0) &quot;&quot;
    [74]=&gt;
    string(0) &quot;&quot;
    [75]=&gt;
    string(0) &quot;&quot;
    [76]=&gt;
    string(0) &quot;&quot;
    [77]=&gt;
    string(0) &quot;&quot;
    [78]=&gt;
    string(0) &quot;&quot;
    [79]=&gt;
    string(0) &quot;&quot;
    [80]=&gt;
    string(0) &quot;&quot;
    [81]=&gt;
    string(0) &quot;&quot;
    [82]=&gt;
    string(0) &quot;&quot;
    [83]=&gt;
    string(1) &quot;0&quot;
    [84]=&gt;
    string(1) &quot;0&quot;
    [85]=&gt;
    string(1) &quot;0&quot;
    [86]=&gt;
    string(18) &quot;a0Qd0000001kMRwEAM&quot;
    [87]=&gt;
    string(9) &quot;Favorable&quot;
    [88]=&gt;
    string(0) &quot;&quot;
    [89]=&gt;
    string(0) &quot;&quot;
    [90]=&gt;
    string(0) &quot;&quot;
    [91]=&gt;
    string(0) &quot;&quot;
    [92]=&gt;
    string(0) &quot;&quot;
    [93]=&gt;
    string(0) &quot;&quot;
    [94]=&gt;
    string(0) &quot;&quot;
  }
  </code></pre>
  <p>And here's the system.indexes collection showing that the Id field is indeed indexed:</p>
  <pre><code>{ &quot;v&quot; : 1, &quot;key&quot; : { &quot;_id&quot; : 1 }, &quot;ns&quot; : &quot;cavers-import.Voters&quot;, &quot;name&quot; : &quot;_id_&quot; }
  { &quot;v&quot; : 1, &quot;key&quot; : { &quot;Id&quot; : 1 }, &quot;ns&quot; : &quot;cavers-import.Voters&quot;, &quot;name&quot; : &quot;Id_1&quot; }
  </code></pre>