Activity

1. crwilcox

   transferred this issue fromgoogleapis/google-cloud-pythonon Feb 20, 2020
2. product-auto-label

   added

   api: storageIssues related to the googleapis/python-storage API.Issues related to the googleapis/python-storage API.

   on Feb 20, 2020
3. crwilcox

   added

   priority: p1Important issue which blocks shipping the next release. Will be fixed prior to next release.Important issue which blocks shipping the next release. Will be fixed prior to next release.

   performance

   on Feb 20, 2020
4. crwilcox commented on Feb 20, 2020

   

   crwilcox

   on Feb 20, 2020

   Last edited by crwilcox

   Contributor

   More actions

   It might be interesting to log the http traffic and inspect what is going on.

   Python

   Enabling HTTP requests in Python GCS library can be done using the logging module. In the following example, I'm enabling logging.DEBUG in the example:

   from google.cloud import storage
   # Python3 required
   import http
   http.client.HTTPConnection.debuglevel=5
   # Necessary to turn on logging
   
   storage_client = storage.Client()
   
   blobs = storage_client.list_blobs("anima-frank")
   for blob in blobs:
       print(blob.name)
   

   Ref: https://docs.python.org/3/library/logging.html
   Ref: https://docs.python.org/2/library/logging.html

   GSUTIL

   gsutil has the flag --debug to enable HTTP request logs

   For example:

   gsutil --debug ls gs://bucket-name

   Ref: https://cloud.google.com/storage/docs/gsutil/addlhelp/TopLevelCommandLineOptions
5. braussjoss commented on Feb 20, 2020

   

   braussjoss

   on Feb 20, 2020

   Author

   More actions

   httplog_4workers_20files.txt
   httplog.txt

   "Per Chris's request I ran the test program with HTTP logging turned on. Here is the output for a run with 1 worker retrieving one file."
6. crwilcox commented on Feb 20, 2020

   

   crwilcox

   on Feb 20, 2020

   Last edited by crwilcox

   Contributor

   More actions

   First off, I made some test data by running this locally and uploading to a directory in storage:

   for n in {1..1000}; do                        
       dd if=/dev/urandom of=file$( printf %03d "$n" ).data bs=1 count=1024
   done
   

   I also made some small modifications to the code to make it a bit more flexible.

   • I set defaults in the file to make running in a debugger easier. if you set your own they will still be used.
   • the code didn't support objects without metadata. It checks now before assuming there is metadata to access.

   code.txt

   log_crw_100f_10t.txt
7. crwilcox commented on Feb 21, 2020

   

   crwilcox

   on Feb 21, 2020

   Last edited by crwilcox

   Contributor

   More actions

   After a bit of investigation. testing from my network (Seattle, WA). running 8 workers on a machine with a Quad-Core Intel Core i7 (8 vCores). Bucket is multiregion us.

   I tracked metadata retrieval, downloading the 1kb file, setting metadata. Each takes right around .15 - .25 seconds. If it takes longer than .25 I print a warning. The attached log has a single warning from a metadata update that took .27 seconds.

   The code has change slightly from above as I added additional logging.
   code.txt
   log_1000f_8w.txt

   Time to download using code.py is around 40 seconds (timing is capturing the final sleep on threads so actual time is less)

   Using gsutil -m cp -r gs://bucket/demo-data/ I see it taking 35.76s
8. frankyn

   assigned

   crwilcox

   on Feb 21, 2020
9. crwilcox commented on Feb 21, 2020

   

   crwilcox

   on Feb 21, 2020

   Contributor

   More actions

   Closing this out as customer has been helped. Will open bugs to dig into specific things we can do to help folks avoid this in the future. It seems the threaded version of this code has some contention. Moving to multiprocessing is much faster.

   Using threads: ~30 seconds
   After moving to multiprocesing:
   16 workers: 19.4 seconds
   32 workers: 13.2 seconds
   64 workers: 10.3 seconds
   128 workers: 9.1 secondsF

   multiprocessing_code.txt
10. crwilcox

    closed this as completedon Feb 21, 2020