[postgis-devel] Re: [postgis-users] GIST index speed

[Paul Ramsey]

Mark,

Is it possible something terrible is happening in LWGEOM_gist_consistent?

The place the slow differs from the fast is that the slow spends a
great deal of time in _memcpy, which is driven by toast fetching,
which is driven by LWGEOM_gist_consistent.

There's lots of activity in the operating system, as well, in
vm_fault, which again reflects the idea that we are doing a lot of
memory allocation.

P.

On Mon, Jun 9, 2008 at 7:48 AM, Mark Cave-Ayland
<mark.cave-ayland at siriusit.co.uk> wrote:
> Paul Ramsey wrote:
>>
>> Bummer. Well if you need any other cock-eyed theories, let me know :)
>>
>> P
>
> Hi Paul,
>
> Please feel free to add more: I think it's that we're doing something
> strange with palloc/pfree/TOAST, maybe casting, or it's something in the
> PostgreSQL index AM. Do you have any success with profiling under OS X? If
> so, it would be good to get at least a working profile output of both query
> cases, so we can try and determine where the time is being swallowed during
> the index scan.
>
>
> ATB,
>
> Mark.
>
> --
> Mark Cave-Ayland
> Sirius Corporation - The Open Source Experts
> http://www.siriusit.co.uk
> T: +44 870 608 0063
> _______________________________________________
> postgis-users mailing list
> postgis-users at postgis.refractions.net
> http://postgis.refractions.net/mailman/listinfo/postgis-users
>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: screenshot_01.gif
Type: image/gif
Size: 106060 bytes
Desc: not available
Url : http://lists.refractions.net/pipermail/postgis-devel/attachments/20080609/2bb8ef60/screenshot_01-0001.gif
-------------- next part --------------
# Report 1 - Session 2 - Time Profile of Everything
SharkProfileViewer
# Generated from the visible portion of the outline view
+ 13.4% __memcpy (commpage [libSystem.B.dylib])
| + 13.3% toast_fetch_datum (postgres)
| | + 13.3% heap_tuple_untoast_attr (postgres)
| | | - 13.3% LWGEOM_gist_consistent (liblwgeom.so)
| - 0.0% heap_tuple_untoast_attr (postgres)
| - 0.0% hash_search_with_hash_value (postgres)
| - 0.0% hash_search (postgres)
  9.1% lo_alltraps (mach_kernel)
- 8.7% ml_set_interrupts_enabled (mach_kernel)
+ 5.6% blkclr (mach_kernel)
| + 3.7% 0x521a6c [unreadable] (mach_kernel)
| | + 3.7% pmap_zero_page (mach_kernel)
| | | + 3.7% vm_fault_cleanup (mach_kernel)
| | | | - 3.7% vm_fault (mach_kernel)
| - 1.9% pmap_zero_page (mach_kernel)
| - 0.0% bzero_phys (mach_kernel)
- 3.0% pmap_enter (mach_kernel)
- 2.3% index_getnext (postgres)
- 2.2% copyout_kern (mach_kernel)
- 2.1% LWLockAcquire (postgres)
- 2.1% pmap_get_mapwindow (mach_kernel)
- 2.0% pmap_remove_range (mach_kernel)
- 1.9% LWLockRelease (postgres)
- 1.5% vm_fault (mach_kernel)
- 1.5% mutex_unlock (mach_kernel)
- 1.4% vm_page_lookup (mach_kernel)
- 1.3% hash_search_with_hash_value (postgres)
- 1.3% hw_lock_unlock (mach_kernel)
- 1.1% hw_lock_to (mach_kernel)
- 1.1% vm_map_lookup_locked (mach_kernel)
- 1.0% vm_page_grab (mach_kernel)
- 1.0% hash_any (postgres)
- 1.0% btgettuple (postgres)
  1.0% lo_unix_scall (mach_kernel)
- 0.9% mutex_lock (mach_kernel)
- 0.9% pmap_page_protect (mach_kernel)
- 0.8% OSAddAtomic (mach_kernel)
- 0.8% toast_fetch_datum (postgres)
- 0.8% _bt_checkkeys (postgres)
- 0.8% usimple_lock (mach_kernel)
- 0.8% pmap_pte (mach_kernel)
- 0.8% FunctionCall2 (postgres)
- 0.7% user_trap (mach_kernel)
- 0.7% ReleaseAndReadBuffer (postgres)
- 0.6% vm_page_insert_internal (mach_kernel)
- 0.6% vm_fault_enter (mach_kernel)
- 0.6% LockBuffer (postgres)
- 0.6% ReadBuffer_common (postgres)
- 0.6% UnpinBuffer (postgres)
- 0.6% pmap64_pdpt (mach_kernel)
- 0.6% _mutex_lock_spin (mach_kernel)
- 0.5% vm_fault_cleanup (mach_kernel)
- 0.5% AllocSetAlloc (postgres)
- 0.5% lck_rw_lock_shared (mach_kernel)
- 0.5% _bt_next (postgres)
- 0.5% bzero_phys (mach_kernel)
- 0.4% chudxnu_cpu_free (mach_kernel)
- 0.4% bcmp (libSystem.B.dylib)
- 0.4% thread_cancel_timer (mach_kernel)
- 0.4% mmap (libSystem.B.dylib)
- 0.4% pmap64_pde (mach_kernel)
- 0.4% vm_page_remove (mach_kernel)
- 0.4% PinBuffer (postgres)
- 0.4% lck_rw_done (mach_kernel)
- 0.4% vm_page_free_prepare (mach_kernel)
- 0.4% vm_object_lock (mach_kernel)
- 0.3% ResourceOwnerForgetBuffer (postgres)
- 0.3% memcpy (libSystem.B.dylib)
- 0.3% vm_page_release (mach_kernel)
- 0.3% heap_page_prune_opt (postgres)
- 0.3% unix_syscall (mach_kernel)
- 0.3% lck_rw_lock_exclusive (mach_kernel)
- 0.3% vm_page_alloc (mach_kernel)
- 0.3% LockAcquire (postgres)
- 0.3% _bt_compare (postgres)
- 0.3% vm_map_enter (mach_kernel)
- 0.3% munmap$UNIX2003 (libSystem.B.dylib)
- 0.3% _bt_readpage (postgres)
- 0.3% vm_object_hash_entry_free (mach_kernel)
- 0.2% HeapTupleSatisfiesToast (postgres)
- 0.2% current_processor (mach_kernel)
- 0.2% lseek (libSystem.B.dylib)
- 0.2% ast_pending (mach_kernel)
- 0.2% _disable_preemption (mach_kernel)
- 0.2% vm_map_simplify (mach_kernel)
- 0.2% lock_read (mach_kernel)
- 0.2% lck_mtx_unlock (mach_kernel)
- 0.2% vm_page_activate (mach_kernel)
- 0.2% LWGEOM_gist_consistent (liblwgeom.so)
- 0.2% kernel_preempt_check (mach_kernel)
- 0.2% gistnext (postgres)
- 0.2% _bt_first (postgres)
- 0.2% LockRelease (postgres)
- 0.1% lck_mtx_lock_spin (mach_kernel)
- 0.1% oideq (postgres)
- 0.1% lck_rw_done_gen (mach_kernel)
- 0.1% free (libSystem.B.dylib)
- 0.1% copypv (mach_kernel)
- 0.1% szone_malloc (libSystem.B.dylib)
- 0.1% malloc (libSystem.B.dylib)
- 0.1% get_hash_value (postgres)
- 0.1% BufTableHashCode (postgres)
- 0.1% _bt_binsrch (postgres)
- 0.1% usimple_unlock (mach_kernel)
- 0.1% tag_hash (postgres)
- 0.1% szone_free (libSystem.B.dylib)
- 0.1% lck_rw_free (mach_kernel)
  0.1% [NO PC RECORDED] (mach_kernel)
- 0.1% szone_size (libSystem.B.dylib)
- 0.1% UnGrantLock (postgres)
- 0.1% ResourceOwnerRememberBuffer (postgres)
- 0.1% read$UNIX2003 (libSystem.B.dylib)
- 0.1% pmap_put_mapwindow (mach_kernel)
- 0.1% MemoryContextAlloc (postgres)
- 0.1% lck_mtx_lock (mach_kernel)
- 0.1% kauth_cred_uthread_update (mach_kernel)
- 0.1% cluster_pageout (mach_kernel)
- 0.1% _bt_search (postgres)
- 0.1% vm_page_free (mach_kernel)
- 0.1% vm_map_submap_pmap_clean (mach_kernel)
- 0.1% pmap_remove (mach_kernel)
- 0.1% AllocSetFree (postgres)
- 0.1% allocate_pages (libSystem.B.dylib)
- 0.1% vm_map_enter_cpm (mach_kernel)
- 0.1% ReleaseBuffer (postgres)
- 0.1% pmap_high_map_vaddr (mach_kernel)
- 0.1% large_and_huge_malloc (libSystem.B.dylib)
- 0.1% __gettimeofday (commpage [libSystem.B.dylib])
- 0.1% vnode_cache_is_authorized (mach_kernel)
- 0.1% vm_page_lru (mach_kernel)
- 0.1% vm_object_lock_try_shared (mach_kernel)
- 0.1% vm_map_enter_mem_object (mach_kernel)
- 0.1% pmap_disconnect (mach_kernel)
- 0.1% mac_vnode_check_read (mach_kernel)
- 0.1% IsSharedRelation (postgres)
- 0.1% hfs_vnop_read (mach_kernel)
- 0.1% hash_search (postgres)
- 0.1% flush_tlb64 (mach_kernel)
- 0.1% vm_page_zero_fill (mach_kernel)
- 0.1% vm_page_free_list (mach_kernel)
- 0.1% pmap_zero_page (mach_kernel)
- 0.1% phys_attribute_test (mach_kernel)
- 0.1% pgstat_initstats (postgres)
- 0.1% malloc_zone_malloc (libSystem.B.dylib)
- 0.1% inval_copy_windows (mach_kernel)
- 0.1% ExecStoreTuple (postgres)
- 0.1% uiomove64 (mach_kernel)
- 0.1% StrategyGetBuffer (postgres)
- 0.1% SHMQueueInit (postgres)
- 0.1% ResourceOwnerEnlargeBuffers (postgres)
- 0.1% nosys (mach_kernel)
- 0.1% ExecAgg (postgres)
- 0.1% dyld_stub_memcpy (postgres)
- 0.1% btoidcmp (postgres)
- 0.1% __nanotime (commpage [libSystem.B.dylib])
- 0.0% pg_detoast_datum (postgres)
- 0.0% pfree (postgres)
- 0.0% mdread (postgres)
- 0.0% gettimeofday (libSystem.B.dylib)
- 0.0% getbox2d_p (liblwgeom.so)
- 0.0% get_threadtask (mach_kernel)
- 0.0% FunctionCall3 (postgres)
- 0.0% FileRead (postgres)
- 0.0% ExecProcNode (postgres)
- 0.0% current_task (mach_kernel)
- 0.0% current_proc (mach_kernel)
- 0.0% current_map (mach_kernel)
- 0.0% BufferGetBlockNumber (postgres)
- 0.0% btrescan (postgres)
- 0.0% zfree (mach_kernel)
- 0.0% vn_rdwr (mach_kernel)
- 0.0% vfs_fsprivate (mach_kernel)
- 0.0% vfs_context_current (mach_kernel)
- 0.0% SHMQueueInsertBefore (postgres)
- 0.0% ReadBuffer (postgres)
- 0.0% MemoryContextReset (postgres)
- 0.0% lck_mtx_try_lock (mach_kernel)
- 0.0% InstrStopNode (postgres)
- 0.0% GrantLockLocal (postgres)
- 0.0% get_bsdthread_info (mach_kernel)
- 0.0% FunctionCall4 (postgres)
- 0.0% FileSeek (postgres)
- 0.0% deallocate_pages (libSystem.B.dylib)
- 0.0% adjust_vm_object_cache (mach_kernel)
- 0.0% vm_map_remove (mach_kernel)
- 0.0% TransactionIdPrecedes (postgres)
- 0.0% TerminateBufferIO (postgres)
- 0.0% smgrread (postgres)
- 0.0% ResourceOwnerForgetRelationRef (postgres)
- 0.0% RelationIdGetRelation (postgres)
- 0.0% RelationGetIndexScan (postgres)
- 0.0% memory_object_control_uiomove (mach_kernel)
- 0.0% mac_file_check_change_offset (mach_kernel)
- 0.0% lock_done (mach_kernel)
- 0.0% IndexScanEnd (postgres)
- 0.0% gistgettuple (postgres)
- 0.0% fmgr_info_cxt_security (postgres)
- 0.0% current_thread (mach_kernel)
- 0.0% copyoutphys_user (mach_kernel)
- 0.0% copyin (mach_kernel)
- 0.0% advance_aggregates (postgres)
- 0.0% AcceptInvalidationMessages (postgres)
- 0.0% _sysenter_trap (libSystem.B.dylib)
- 0.0% _bt_steppage (postgres)
- 0.0% vm_purgeable_q_advance_all (mach_kernel)
- 0.0% vm_map_create (mach_kernel)
- 0.0% vfs_getvfs_by_mntonname (mach_kernel)
- 0.0% UnlockReleaseBuffer (postgres)
- 0.0% uio_resid (mach_kernel)
- 0.0% SIGetDataEntry (postgres)
- 0.0% ResourceOwnerRememberRelationRef (postgres)
- 0.0% ResourceOwnerEnlargeRelationRefs (postgres)
- 0.0% ReceiveSharedInvalidMessages (postgres)
- 0.0% munge_wwwwwwww (mach_kernel)
- 0.0% munge_wwwwwl (mach_kernel)
- 0.0% memory_object_lock_page (mach_kernel)
- 0.0% mach_vm_deallocate (mach_kernel)
- 0.0% LockRelationOid (postgres)
- 0.0% large_free_no_lock (libSystem.B.dylib)
- 0.0% IndexNext (postgres)
- 0.0% index_rescan (postgres)
- 0.0% HeapTupleSatisfiesMVCC (postgres)
- 0.0% cpu_number (mach_kernel)
- 0.0% cluster_read_ext (mach_kernel)
- 0.0% BufTableLookup (postgres)
- 0.0% AllocSetReset (postgres)
- 0.0% _rtc_nanotime_read (mach_kernel)
- 0.0% _bt_getroot (postgres)
- 0.0% __commpage_gettimeofday (libSystem.B.dylib)
- 0.0% zalloc_canblock (mach_kernel)
- 0.0% vnode_removefsref (mach_kernel)
- 0.0% vnode_isfifo (mach_kernel)
- 0.0% vm_map_lookup_entry (mach_kernel)
- 0.0% RelationDecrementReferenceCount (postgres)
- 0.0% relation_open (postgres)
- 0.0% read (mach_kernel)
- 0.0% munmap (mach_kernel)
- 0.0% mdopen (postgres)
- 0.0% lock_write (mach_kernel)
- 0.0% int8inc (postgres)
- 0.0% FunctionCall1 (postgres)
- 0.0% fp_lookup (mach_kernel)
- 0.0% FileAccess (postgres)
- 0.0% file_drop (mach_kernel)
- 0.0% ExecScan (postgres)
- 0.0% ExecIndexScan (postgres)
- 0.0% CompareExtendedCatalogKeys (mach_kernel)
- 0.0% cluster_read (mach_kernel)
- 0.0% clock_get_system_microtime (mach_kernel)
- 0.0% advance_transition_function (postgres)
- 0.0% _bt_relandgetbuf (postgres)
- 0.0% _bt_preprocess_keys (postgres)
- 0.0% _bt_moveright (postgres)
- 0.0% _bt_checkpage (postgres)
- 0.0% vnode_put (mach_kernel)
- 0.0% vm_object_lock_shared (mach_kernel)
- 0.0% vm_map_entry_insert (mach_kernel)
- 0.0% vfs_context_proc (mach_kernel)
- 0.0% timevalsub (mach_kernel)
- 0.0% StartBufferIO (postgres)
- 0.0% SHMQueueDelete (postgres)
- 0.0% ScanKeyEntryInitializeWithInfo (postgres)
- 0.0% RemoveLocalLock (postgres)
- 0.0% RelationIncrementReferenceCount (postgres)
- 0.0% read_nocancel (mach_kernel)
- 0.0% PageHeaderIsValid (postgres)
- 0.0% OSCompareAndSwap (mach_kernel)
- 0.0% munge_ww (mach_kernel)
- 0.0% mmap$UNIX2003 (libSystem.B.dylib)
- 0.0% memmove (libSystem.B.dylib)
- 0.0% mac_policy_list_conditional_busy (mach_kernel)
- 0.0% lwgeom_hasBBOX (liblwgeom.so)
- 0.0% LWGEOM_gist_decompress (liblwgeom.so)
- 0.0% LockCheckConflicts (postgres)
- 0.0% is_file_clean (mach_kernel)
- 0.0% IS_64BIT_PROCESS (mach_kernel)
- 0.0% InstrStartNode (postgres)
- 0.0% index_endscan (postgres)
- 0.0% index_beginscan_internal (postgres)
- 0.0% heap_tuple_untoast_attr (postgres)
- 0.0% heap_open (postgres)
- 0.0% GrantLock (postgres)
- 0.0% gistdentryinit (postgres)
- 0.0% gistcheckpage (postgres)
- 0.0% copyin_kern (mach_kernel)
- 0.0% CleanUpLock (postgres)
- 0.0% btbeginscan (postgres)
- 0.0% vnode_put_locked (mach_kernel)
- 0.0% vnode_isreg (mach_kernel)
- 0.0% vnode_getwithref (mach_kernel)
- 0.0% vnode_fsnode (mach_kernel)
- 0.0% UnlockRelationId (postgres)
- 0.0% uio_offset (mach_kernel)
- 0.0% uio_addiov (mach_kernel)
- 0.0% ScanKeyInit (postgres)
- 0.0% relation_close (postgres)
- 0.0% ProcQueueInit (postgres)
- 0.0% proc_fdunlock (mach_kernel)
- 0.0% PinBuffer_Locked (postgres)
- 0.0% munge_wlw (mach_kernel)
- 0.0% malloc_zone_free (libSystem.B.dylib)
- 0.0% LockTagHashCode (postgres)
- 0.0% index_open (postgres)
- 0.0% index_getprocinfo (postgres)
- 0.0% index_beginscan (postgres)
- 0.0% hash_uint32 (postgres)
- 0.0% get_bsdtask_info (mach_kernel)
- 0.0% fp_getfvp (mach_kernel)
- 0.0% fp_drop (mach_kernel)
- 0.0% fmgr_info_copy (postgres)
- 0.0% ExecIndexBuildScanKeys (postgres)
- 0.0% dyld_stub_mmap$UNIX2003 (libSystem.B.dylib)
- 0.0% dyld_stub_gettimeofday (postgres)
- 0.0% copyin_user (mach_kernel)
- 0.0% BufTableInsert (postgres)
- 0.0% BufTableDelete (postgres)
- 0.0% btendscan (postgres)
- 0.0% advisory_read (mach_kernel)
- 0.0% _enable_preemption (mach_kernel)
- 0.0% _bt_relbuf (postgres)
- 0.0% _bt_mark_scankey_with_indoption (postgres)
- 0.0% _bt_getbuf (postgres)
- 0.0% __pthread_testcancel (mach_kernel)