This is an investigation memo when the processing of the Rails application running on Heroku was slow. In conclusion, the cloud storage part of GCP used for image storage was the bottleneck.
I am building and operating a hobby website using Rails with Heroku's free plan. From the beginning, the process wasn't very fast, but I used to cache SQL with Redis, so I thought it would be like this if it was free.
However, I noticed that only some pages were faster than others, so I decided to investigate what was the cause.
Although it is a general method, I decided to output the log with the following command and check the processing time.
heroku logs --tail
By default, Rails will give you various processing times in the DEBUG log, so I decided to check that first.
At first I thought that the SQL of the uncached part was slow, but As for SQL, the cache worked and I couldn't find any slow queries.
However, instead, there were some logs that took 100ms or more for the processing time as shown below.
GCS Storage (169.9ms) Checked if file exists at key: variants/xxxx
The site uploaded the image to GCS, and I could guess that the part was related. You can also see that the corresponding function of Active Storage is affected by keywords such as variant.
Regarding this variant, please see the reference materials below, but in simple terms, it is a function to resize etc. without using the uploaded image as it is. Reference
If you use this function, you do not have to implement the resizing process yourself, and it is a very convenient function that saves the resized image at the first access and reuses it behind the scenes. However, this time it seems that the function of Ki is doing something bad.
I decided that further investigation would be difficult, so I googled if there were other similar symptoms for the time being.
As a result, I found some things that seemed to be similar symptoms such as S3 on AWS.
https://stackoverflow.com/questions/49415911/activestorage-checking-if-file-exists-is-slow https://github.com/rails/rails/issues/32548 https://github.com/rails/rails/pull/37901
When I read it diagonally with my poor English ability, I made the following judgment. (I apologize if I'm wrong.)
--The existence of the converted and saved image is checked, and it takes time there. --Already made the corresponding fix and included in Rails version (6.1)
Looking at the above, I thought that the latest version would solve the problem, but unfortunately 6.1 has not been released yet ...
In conclusion, I decided to stop the compression process by varian and use the original image. Regarding the original image, it is judged that it will not be a problem because it is manually resized and corrected with an image tool etc. before uploading.
As a result, the original log that took more than 100ms disappeared and was changed to the following 1ms processing, and I feel that the speed has become faster.
GCS Storage (1.5ms) Generated URL for file at key: xxxx
So, it was because it took a long time to use the image processed by Active Storage in cloud storage (GCS). We decided to take a delicate approach by not using the function without taking fundamental measures.
It seems that Rails 6.1 will be released soon, so I would like to use the function again after the update.
It is Active Storage that you can easily use cloud storage such as S3 and GCS, but thanks to various hiding behind the scenes, it turned out that it affects the performance in places that can not be seen.