ActiveRecord based on Yii 2, during operation, the CPU usage of Redis is 100% analysis and solution

1. At 2017-06-18 19:36:00, that is, when the game starts, the response time of the application is 51.8ms, and the response time is normal, as shown in Figure 1

Figure 1

2. During the entire football game, the response time is increasing linearly, at 2017-06-18 20:30:00 to 2017-06-18 At 20:40:00, the response time decreased because the game was in the midfield period at this time, and the game data sent to the server was basically unchanged, so the processing logic was simple, as shown in Figure 2

Figure 2

3. At 2017-06-18 21:25:00, that is, when the game is about to end, the response time of the application is 2320ms, and the average response time required by the business goal is 150ms, so the performance cannot meet the business requirements, as shown in Figure 3

Figure 3

4. In the transaction trace of APM, it can be found that in a request with a response time of 5710 ms, the redis-related operation consumes 4390 MS, occupying a proportion of 77%, HttpClient calls another interface, and its interface also uses Redis, so the analysis result is that Redis is the performance bottleneck, as shown in Figure 4

Figure 4

5. In the trace details of the transaction trace of apm, found 57.25% of the time spent by shujujixi\models\redis\gameplayerdata::gameplayerdatabyshujujixi is 57.25%, as shown in Figure 5

Figure 5

6. Continue to expand until it cannot be expanded, and find that yii\redis\connection::parseResponse needs to analyze its operation mechanism, as shown in Figure 6

Figure 6

7. In Alibaba Cloud monitoring, at 2017-06-18 19:36:00, that is, when the game starts, the CPU usage rate of Redis is 1.9%, as shown in Figure 7

Figure 7

8. During the entire football game, in Alibaba Cloud monitoring, the CPU usage of Redis is increasing linearly, at 2017-06-18 20:30:00 to 2017-06-18 At 20:40:00, the CPU usage of Redis declines because the game is in the midfield period at this time, and the game data sent to the server is basically unchanged, so the processing logic is simple, and the entire curve is completely proportional to the response time, as shown in Figure 8

8

9. In Alibaba Cloud monitoring, at 2017-06-18 21:27:00, that is, when the game is about to end, the CPU usage rate of Redis is 100%, as shown in Figure 9

Figure 9

10. In Alibaba Cloud monitoring, at 2017-06-18 21:28:00, that is, when the game is about to end, the number of Redis used connections is 54, reaching the peak, as shown in Figure 10

Figure 10

11. Now it is necessary to analyze what causes the CPU usage rate of Redis to be 100%. 78% of the time spent, as shown in Figure 11

Figure 11

12. In the Trace Details of the APM’s transaction trace, find the application code (in yii\Redis\ActiveRecord::deleteAll) The most time-consuming, basically determine the root cause of ActiveRecord-related operations to cause the CPU usage of Redis to be 100%, as shown in Figure 12

Figure 12

13. In the PRO environment, it is prepared to implement 2 versions of a typical request. The first version of ActiveRecord-related operations are basically query and modification, and the second version of ActiveRecord-related operations are basically query and insert. It is convenient to confirm whether the number of keys in an ActiveRecord model will increase the CPU usage rate of Redis, first clear the Redis data generated by the scheduled task, and the number of keys is 3170, as shown in Figure 13

Figure 13

14. In the Pro environment, after the first version of the request runs for 2 hours, the number of Redis data, the number of keys is 3220, and only 50 keys are added, as shown in Figure 14

Figure 14

15. In the Pro environment, during the operation of the entire typical request, in Alibaba Cloud monitoring, the maximum CPU usage rate of Redis is 2.6%, at 2017-06-27 16:50:00 After that, the CPU usage of Redis remained at 0.6%, because at this time, the game data sent to the server is basically unchanged, so the processing logic is simple, as shown in Figure 15

Figure 15

16. In the Pro environment, during the operation of the entire typical request, the response time is basically stable, and the maximum response time is 266ms. After 2017-06-27 16:50:00, the response time drops because at this time, the game data sent to the server is basically unchanged, so the processing logic is simple, as shown in Figure 16

Figure 16

17. Clear the redis data first, and then the redis data generated by the timing task, the number of keys is 2909, as shown in Figure 17

Figure 17

18. In the PRO environment, after the second version of the request runs for 2 hours, the number of redis data, the number of keys is 89840, and 86931 keys are added, as shown in Figure 18

18

19. The number of keys of the Redis model operated by the second version of the request is 79527, as shown in Figure 19

Figure 19

20. In the PRO environment, the second version of the request, during the operation of the entire typical request, in Alibaba Cloud monitoring, the maximum CPU usage rate of Redis is 66.8%, as shown in Figure 20

Figure 20

21. Based on the current analysis results, it can be determined that when the number of keys of a model operated by ActiveRecord is too large, the CPU usage of Redis will be greatly improved, but it is caused by the query or insertion, and further confirmation is required, as shown in Figure 21

Figure 21

22. Modify the query plan, set the count(ID) is adjusted to exists(), that is, all keys in the query model that meet the conditions are adjusted to 1 key in the query model, as shown in Figure 22

Figure 22

23. The number of keys of the Redis model operated by the third version of the request is 81277 in the PRO environment, as shown in Figure 23

Figure 23

24. In the Pro environment, the third version of the request, during the operation of the entire typical request, in Alibaba Cloud monitoring, the maximum CPU usage rate of Redis is 11.8%, as shown in Figure 24

Figure 24

25. Based on the current analysis results, it can be determined that when the number of keys of a model operated by ActiveRecord is too large, the CPU usage of Redis It will be greatly improved, and it is the most relevant to the query, but the performance comparison between the query and the insert needs to be further confirmed, code, comment out the query, and only keep the insert operation, as shown in Figure 25

Figure 25

26. The number of keys of the Redis model operated by the 4th version of the request is 81947 in the PRO environment, as shown in Figure 26

Figure 26

27. In the Pro environment, the fourth version of the request, during the operation of the entire typical request, in Alibaba Cloud monitoring, the maximum CPU usage rate of Redis is 2.2%, as shown in Figure 27

Figure 27

28. Adjust count() to exists() to improve the query performance, as shown in Figure 28

Figure 28

29. Reconstruct some ActiveRecord to redis native command implementation. During the entire football game, in Alibaba Cloud monitoring, the maximum CPU usage rate of Redis is 21.1%, so the response time is normal, as shown in Figure 29

Figure 29

30. Summary: ActiveRecord of Yii 2, the relevant method calculates the pressure ranking for the CPU of Redis: insert() < one()/exists() < count()/all(), when the number of keys of a redis model exceeds 10000, if you want to perform a query (with where condition) operation, it is recommended not to use ActiveRecord, as shown in Figure 30

Figure 30