Degraded performance in 1.5.1 compared to 1.4.8?

232
3
02-27-2019 03:58 PM
AngusHooper1
Occasional Contributor II

I am currently testing Pro 2.3.0 rollout for production users and the only issue that has currently been highlighted is that the python api in jupyter notebook is considerably slower.

 

Pro 2.2.4, API 1.4.8

 

from arcgis import GIS

from datetime import datetime

<name of gis> = GIS(url=”<GIS url>”, username=”user@domain”)

print(gis.properties.user.username)

print(datetime.now())

content_manager = gis.content

all_content = content_manager.search(query=”*”, max_items=9999)

print(len(all_content))

end = datetime.now()

print(datetime.now())

Time Taken = 0.7 seconds

 

 

Pro 2.3, API 1.5.1

 

from arcgis import GIS

from datetime import datetime

<name of gis> = GIS(url=”<GIS url>”, username=”user@domain”)

print(gis.properties.user.username)

print(datetime.now())

content_manager = gis.content

all_content = content_manager.search(query=”*”, max_items=9999)

print(len(all_content))

end = datetime.now()

print(datetime.now())

Time Taken = 4 minutes 9 seconds

 

FYI, the above is just a sample script. Most of my scripts at 1.4.8 are now almost unusable at 1.5.1 because they take hours to run rather than under 30 seconds. Did anyone else experience this degradation going from 1.4.8 to 1.5.1?

Tags (3)
3 Replies
KevinTientcheu3
New Contributor II

Hello Angus,

Are you working with Portal for ArcGIS or ArcGIS Online? Are you able to test your 1.4.8 script again and see if it still works as expected? 

Also, are you able to test with the arcgis module that is available through Anaconda rather than the one installed by ArcGIS Pro and see if there is any difference?

Thanks! 

0 Kudos
TristanMcHardie
New Contributor III

Hi Kevin Tientcheu,

I'm seeing the same issue too since ArcGIS Pro 2.3.

I'm unable to try this in v1.6 in Anaconda due to proxy hell, but I've tried setting the logging level to debug in v1.5.1 using a modified version of Angus Hooper's script from above:

import arcgis
from datetime import datetime
import logging

logging.basicConfig(level=logging.DEBUG)

start = datetime.now()

gis = arcgis.gis.GIS("pro")
print(gis.properties.user.username)
print(datetime.now() - start)

all_content = gis.content.search(query="*", max_items=10)
print(len(all_content))
print(datetime.now() - start)‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

The logger outputs each request and response, and contains the full JSON for each response. To keep things simple, I've removed the guts of the JSON, removed sensitive information, and shortened the item IDs to four characters:

DEBUG:arcgis._impl.portalpy:Connecting to portal: www.arcgis.com
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/, {'f': 'json'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/, {"currentVersion":"7.1"}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/portals/self, {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/portals/self, {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/community/users/..., {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/community/users/..., {...}
[my username]
0:00:04.059151
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=1, num=10)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 1, 'num': 10, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/content/items/4214..., {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/content/items/4214..., {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/content/items/ecb5..., {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/content/items/ecb5..., {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/content/items/4e02..., {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/content/items/4e02..., {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/content/items/370b..., {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/content/items/370b..., {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/content/items/6cab..., {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/content/items/6cab..., {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/content/items/2a24..., {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/content/items/2a24..., {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/content/items/1d70..., {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/content/items/1d70..., {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/content/items/c659..., {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/content/items/c659..., {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/content/items/6f46..., {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/content/items/6f46..., {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/content/items/b43b..., {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/content/items/b43b..., {...}
10
0:00:41.583742‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

The print statements from my code are shown on lines 8, 9, 33, and 34. Time taken to search for max 10 items: 41.6 seconds.

You can see the search request and response in lines 11 and 12.

Lines 13-32 are individual requests and responses for the ten items returned. It appears the Python API is hydrating items as they're returned from the search operation, which I don't think this was happening prior to v1.5.1.

I suspect this is the bottleneck.

If I manage to resolve my proxy hell, I'll report back with the results of running the same thing in earlier and later versions of the Python API through Anaconda.

TristanMcHardie
New Contributor III

I've managed to try v1.6.1 since my last post. Results below while attempting to search for max 1,000,000 items:

DEBUG:arcgis._impl.portalpy:Connecting to portal: www.arcgis.com
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/, {'f': 'json'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/, {"currentVersion":"7.1"}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/portals/self, {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/portals/self, {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/community/users/[my username], {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/community/users/[my username], {...}
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/, {'f': 'json', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/, {"currentVersion":"7.1"}
[my username]
0:00:04.763325
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=1, num=100)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 1, 'num': 100, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=101, num=100)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 101, 'num': 100, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=201, num=100)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 201, 'num': 100, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=301, num=100)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 301, 'num': 100, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=401, num=100)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 401, 'num': 100, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=501, num=100)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 501, 'num': 100, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=601, num=100)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 601, 'num': 100, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=701, num=100)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 701, 'num': 100, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=801, num=100)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 801, 'num': 100, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=901, num=100)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 901, 'num': 100, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=1001, num=100)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 1001, 'num': 100, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
INFO:arcgis._impl.portalpy:Searching items (q=* accountid:..., bbox=None, start=1101, num=100)
DEBUG:arcgis._impl.connection:REQUEST: https://www.arcgis.com/sharing/rest/search, {'f': 'json', 'q': '* accountid:...', 'bbox': '', 'start': 1101, 'num': 100, 'sortField': 'avgRating', 'sortOrder': 'desc', 'token': '...'}
DEBUG:arcgis._impl.connection:RESPONSE: https://www.arcgis.com/sharing/rest/search, {...}
1165
0:00:19.930703

This time around, it only took 20 seconds for 1165 items, which is a huge improvement. The search request is broken down into 12 chunks of 100 items at a time. The major difference is that it's not attempting to hydrate each and every item as its created.

So, this regression has been fixed in the Python API itself, but it's not yet available through a standard installation of ArcGIS Pro, as its the default conda environment has the arcgis package pinned at v1.5.*.

To force a conda environment in ArcGIS Pro which uses v1.6.1:

  1. Clone and activate the default Python environment from within ArcGIS Pro itself.
  2. In the Python Command Prompt, run "conda update arcgis --no-pin‍‍".
0 Kudos