[SERVER-9222] On explain() millis value is 0 for GeoSearchCursor Created: 03/Apr/13 Updated: 10/Dec/14 Resolved: 02/Jan/14 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | None |
| Affects Version/s: | 2.2.3 |
| Fix Version/s: | None |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | Aurelien Beltrame | Assignee: | Unassigned |
| Resolution: | Duplicate | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Environment: |
linux ubuntu 12.04 |
||
| Issue Links: |
|
||||||||||||
| Operating System: | ALL | ||||||||||||
| Participants: | |||||||||||||
| Description |
|
On some small fast query with geoSearchCursor, millis always return 0 inside explain() / explain(true) result. To ensure the query is not so fast, then I activate the profiling and query stay at millis:0 in front but at 50 ms in profiling collection (which is slow but more or less what I expected). |
| Comments |
| Comment by Daniel Pasette (Inactive) [ 02/Jan/14 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Duplicate of | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Aurelien Beltrame [ 16/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
I try a simple find() on a collection with thousands documents. Explain provide a value != 0 (I try differents collections (=> differents # docs) to get queries with 20-50 ms). | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Andre de Frere [ 16/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Hi, You specifically mention the geoSearchCursor. Are you seeing this issue only on geo queries, or do you see the same pattern on all fast queries? From the profile output it appears that the query is spending all of it's time a read lock, which could be indicative of reading data and filling the network buffer. | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Aurelien Beltrame [ 04/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
(sorry for layout. I hide database/collection name.) the index called cpd_sparse :
the query is :
the explain
the profile output:
| ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
| Comment by Eliot Horowitz (Inactive) [ 03/Apr/13 ] | ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
|
Can you send an example query, the explain, and the profile output? What's probably causing the difference is that the explain doesn't do the data copy to the network buffers, so just evaluating the query is fast, but when you do it for real there is copying to be done. |