This is a research note when the Rails application running on Heroku was slow to process. In conclusion, the part of GCP’s cloud storage used for image storage was the bottleneck.
- Ruby 2.6.3p62
- Rails 22.214.171.124
We are building and operating a hobby website using Rails with Heroku’s free plan. Although it wasn’t so fast from the beginning, I also thought that if it was free, it would be something like this because I also cached SQL with Redis.
However, I noticed that only some pages were faster than others, so I decided to investigate what caused it.
It is a general method, but I decided to output the log with the following command and check the processing time.
heroku logs --tail
By default, Rails shows various processing times in the DEBUG log, so I decided to check that first.
Log survey results
At first I was wondering if the SQL that was not cached was slow, Regarding SQL, the cache worked and I could not find any slow queries.
However, instead, I found some logs with a processing time of 100 ms or more as shown below.
GCS Storage (169.9ms) Checked if file exists at key: variants/xxxx
The site in question uploaded images to GCS, and I could guess that the parts were related. You can also see from keywords such as variant that the corresponding function of Active Storage is affected.
Regarding this variant, I would like you to see the reference materials below, but in short, it is a function to resize etc. without using the uploaded image as it is. Reference
If you use this function, you do not need to implement resizing processing yourself, and it is a very convenient function because you can save the resized image at the first access and reuse it in the back. However, this time, it seems that the function of Kino has something bad.
We decided that further investigation would be difficult, so I googled if there were any similar symptoms for the time being.
As a result, I found some similar symptoms in AWS S3.
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
After reading diagonally with my poor English ability, I judged as follows. (I apologize if I’m wrong.)
- Checking the existence of the converted and saved image takes time.
- Already made corresponding fixes 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 was not released yet…
In conclusion, I decided to stop the compression process by varian and use the original image. Regarding the original image, it is a judgment that it will not be a problem because the image tool etc. manually adjust the resizing etc. before uploading in the first place.
As a result, the original log that took more than 100ms disappeared, and the processing was changed to 1 millisecond processing as shown below, and I felt that the speed was felt 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 the cloud storage (GCS). We decided to deal with it in a delicate manner, that is, no function is used without taking fundamental measures.
It seems that measures will be taken in Rails 6.1 which will be released eventually, so I will use the function again after updating.
Although it is Active Storage that can easily use cloud storage such as S3 and GCS, it has been found that it can affect the performance in the invisible part because it is hidden in various ways on the back.