我只修改了一段 Java 代码，就将 API 响应时间从 3 秒缩短到了 80 毫秒

内容分享2小时前发布人骄

2 1 0

一个可能导致你的 API 崩溃的性能错误（而你甚至都不知道）

目前是凌晨2点47分。我盯着Grafana仪表盘，好像它们会神奇地自行修复似的。

我们的API响应时间一般在3秒左右，有时会到4秒。运气不好的时候，超时时间会达到7秒。

用户怨声载道，销售团队慌了神。我的经理安排了明天早上进行一次“快速同步”会议——这实则是公司委婉地表达“解释为什么我们的产品快要凉了”的意思。

我什么方法都试过了：

添加了 Redis 缓存（略有协助）
优化数据库查询（效果略有提升）
增加服务器资源（AWS 对此很满意，但作用不大）
重写了一些算法（略有改善）

什么方法都不管用。

后来我找到了缘由。一个愚蠢的Java错误害得我们损失惨重。一个改动就把响应时间从3000毫秒降到了80毫秒。

我会向你们详细解释到底是什么问题，由于我敢肯定你们当中有些人目前正在犯同样的错误。

那个逐渐消亡的API

我们用的是一个相当标准的 REST API。Spring Boot，PostgreSQL，没什么特别的。用户管理、身份验证、一些业务逻辑。典型的企业级应用。

导致问题的端点：

@GetMapping("/api/users/{id}/profile")
public ResponseEntity<UserProfileDTO> getUserProfile(@PathVariable Long id) {
    UserProfileDTO profile = userService.getUserProfile(id);
    return ResponseEntity.ok(profile);
}

看起来很无害，对吧？代码简洁，关注点分离得当，遵循最佳实践。

只是返回用户数据需要 3 秒钟。

仅限一位用户。

起初毫无进展的调查

我做了每个开发者都会做的事——开始记录所有信息。

@GetMapping("/api/users/{id}/profile")
public ResponseEntity<UserProfileDTO> getUserProfile(@PathVariable Long id) {
    long startTime = System.currentTimeMillis();
    
    UserProfileDTO profile = userService.getUserProfile(id);
    
    long endTime = System.currentTimeMillis();
    log.info("Profile fetch took: {}ms", endTime - startTime);
    
    return ResponseEntity.ok(profile);
}

日志显示平均耗时 2800 毫秒。因此，问题肯定出在
userService.getUserProfile()……

我们来看看这项服务：

@Service
public class UserService {
    
    @Autowired
    private UserRepository userRepository;
    
    @Autowired
    private PostRepository postRepository;
    
    @Autowired
    private CommentRepository commentRepository;
    
    @Autowired
    private FriendRepository friendRepository;
    
    public UserProfileDTO getUserProfile(Long userId) {
        User user = userRepository.findById(userId)
            .orElseThrow(() -> new UserNotFoundException(userId));
        
        List<Post> posts = postRepository.findByUserId(userId);
        List<Comment> comments = commentRepository.findByUserId(userId);
        List<Friend> friends = friendRepository.findByUserId(userId);
        
        return UserProfileDTO.builder()
            .user(user)
            .posts(posts)
            .comments(comments)
            .friends(friends)
            .build();
    }
}

这个看起来也没问题。四个简单的查询语句。我逐一检查了：

findById(userId)- 15毫秒
findByUserId(userId)帖子 – 40毫秒
findByUserId(userId)评论 – 35毫秒
findByUserId(userId)给朋友 – 20毫秒

总计：约 110 毫秒。不算好，但也不至于 3 秒。

剩下的2700毫秒到底都去哪儿了？

当我意识到自己是个白痴的那一刻

我启用了 Hibernate SQL 日志记录。你知道，这本来应该是你第一要做的事情，但你却总是忽略它，由于日志很烦人。

spring.jpa.show-sql=true
spring.jpa.properties.hibernate.format_sql=true
logging.level.org.hibernate.type.descriptor.sql.BasicBinder=TRACE

然后我又一次到达了终点。

我的终端爆炸了。

查询。成百上千条。或许成千上万条。他们不停地滚动。滚动。滚动。

SELECT * FROM users WHERE id = 1
SELECT * FROM posts WHERE user_id = 1
SELECT * FROM comments WHERE post_id = 1
SELECT * FROM users WHERE id = 2  -- wait what
SELECT * FROM comments WHERE post_id = 2
SELECT * FROM users WHERE id = 3
SELECT * FROM posts WHERE user_id = 2
SELECT * FROM comments WHERE post_id = 3
...
(200 more queries)

哦，不。

哦不不不。

N+1 问题。Java/Hibernate 性能杀手中的经典案例。而我却像个十足的业余人士一样，一头扎了进去。

到底什么是N+1问题（以及它为何会毁灭我们）

对于那些还不了解的人（如果你还不了解，那么你即将避免许多痛苦）：

当你的代码像这样获取数据时，就会出现 N+1 问题：

第一个查询：获取主实体（1 个查询）
然后：对每个相关实体，再进行一次查询（N 次查询）。

所以，如果你获取一个拥有 100 条帖子的用户，你会得到：

1 条用户查询
对每篇文章的数据进行 100 次查询
总计：101 次查询

在我们的例子中，我们获取的是：

1 位用户
他们的帖子（假设有 50 条）
这些帖子下的评论（假设有 200 条）
发表这些评论的用户（另有 150 位）
用户的朋友（假设有 300 位）
那些朋友发的帖子……

你清楚我的意思。结果查询数量激增至数千条。

每次查询耗时5-10毫秒。算算看，我们浪费的3秒钟就这么过去了。

解决一切问题的“一个改变”

解决方法？只需@EntityGraph添加一条注释。就这么简单。

以下是我在代码仓库中所做的更改：

public interface UserRepository extends JpaRepository<User, Long> {
    
    @EntityGraph(attributePaths = {"posts", "comments", "friends"})
    Optional<User> findById(Long id);
}

就这些。

它的作用是：不再逐个延迟加载相关实体（N+1），而是告知 Hibernate 使用 JOIN 在一次查询中获取所有内容。

之前（N+1 次查询）：

SELECT * FROM users WHERE id = 1;
SELECT * FROM posts WHERE user_id = 1;
SELECT * FROM posts WHERE user_id = 1;
SELECT * FROM posts WHERE user_id = 1;
-- (repeated 50 times)

（一次查询后）：

SELECT u.*, p.*, c.*, f.*
FROM users u
LEFT JOIN posts p ON u.id = p.user_id
LEFT JOIN comments c ON u.id = c.user_id
LEFT JOIN friends f ON u.id = f.user_id
WHERE u.id = 1;

响应时间从3000毫秒降至80毫秒，立竿见影，没有其他任何改动。

我坐在那里大致 5 分钟，不停地刷新端点，观察指标，心想“事情不可能这么简单”。

但实际的确如此。

我应该提及的其他解决方案（但没有使用）

这方法@EntityGraph对我们有效，但并非总是最佳方案。以下是根据您的具体情况提供的其他选择：

1. 在 JPQL 中获取连接

@Query("SELECT u FROM User u " +
       "LEFT JOIN FETCH u.posts " +
       "LEFT JOIN FETCH u.comments " +
       "WHERE u.id = :id")
Optional<User> findByIdWithDetails(@Param("id") Long id);

结果一样，但更明确。我更喜爱 JPQL @EntityGraph，由于它更简洁，但有些人喜爱 JPQL 的控制性。

2. FetchType.EAGER（不要这样做）

@Entity
public class User {
    @OneToMany(fetch = FetchType.EAGER)
    private List<Post> posts;
}

这样做总是会获取相关数据，即使你不需要。这很懒惰（双关语），后来会给你带来麻烦。不要这样做。

3. DTO 预测

@Query("SELECT new com.example.UserProfileDTO(u.id, u.name, p.title) " +
       "FROM User u LEFT JOIN u.posts p WHERE u.id = :id")
UserProfileDTO findUserProfile(@Param("id") Long id);

只获取所需数据。超级适合读取密集型操作。虽然样板代码较多，但如果只需要特定字段，性能会更好。

4. 批量获取

@Entity
public class User {
    @OneToMany
    @BatchSize(size = 10)
    private List<Post> posts;
}

将 N+1 简化为 N/10+1。虽然不如完全解决问题那么好，但如果不能使用 fetch joins，则会有所协助。

为什么这种情况会发生在每个人身上（可能也包括你）？

N+1 问题之所以棘手，是由于：

1. 在开发环境中运行良好。当你用 5 个用户和 10 个帖子进行测试时，即使发出 15 个查询又有什么关系呢？它只需要 50 毫秒。直接发布就行了。

2. 问题逐渐显现。第一个月：100 个用户，没问题。六个月：10,000 个用户，查询量成倍增长，速度开始变慢。等你注意到的时候，危机已经爆发了。

3. 延迟加载是Hibernate 的默认设置。实际上，在大多数情况下，这都是一个明智的默认选择。但这也就意味着，当您知道需要相关数据时，就需要显式地进行优化。

4. 代码看起来很简洁

user.getPosts()

这行看似无害的代码竟然触发了 50 次数据库查询。从表面上看，你根本察觉不到。

如何在生产前发现这个问题

以下是我目前采取的做法（这是我吃过亏才学到的）：

1. 始终在开发环境中启用 SQL 日志记录

spring.jpa.show-sql=true

是啊，日志的确烦人。忍忍吧。总比生产环境着火好。

2. 在测试中使用查询计数器

@Test
public void getUserProfile_shouldNotTriggerNPlusOne() {
    Statistics stats = sessionFactory.getStatistics();
    stats.setStatisticsEnabled(true);
    stats.clear();
    
    userService.getUserProfile(1L);
    
    long queryCount = stats.getQueryExecutionCount();
    assertThat(queryCount).isLessThan(5); // Adjust threshold
}

如果这个测试失败，那么你肯定还有 N+1 这个值。

3. 使用真实数据量进行分析。不要只用 3 个用户进行测试，要用 1000 个用户进行测试。N+1 的影响在小数据聚焦不会显现出来。

4. 使用 Hibernate 统计信息

@Bean
public HibernatePropertiesCustomizer hibernateStatisticsCustomizer() {
    return (properties) -> properties.put("hibernate.generate_statistics", true);
}

然后监控hibernate.statistics生产环境中的指标。您将看到每个端点的查询次数。

无人教授的表演模式

既然说到这里，我就顺便提一下我遇到的其他一些Java性能杀手：

问题：循环中的字符串连接

// 错误的 - 在每次迭代中都会创建一个新的字符串对象
String result = "";
for (String item : items) {
    result += item; // DON'T DO THIS
}

// 正确的
StringBuilder sb = new StringBuilder();
for (String item : items) {
    sb.append(item);
}

问题：资源未关闭

// 错误的
BufferedReader reader = new BufferedReader(new FileReader("file.txt"));
String line = reader.readLine();
// 忘记关闭了——内存泄漏

// 正确的
try (BufferedReader reader = new BufferedReader(new FileReader("file.txt"))) {
    String line = reader.readLine();
} // 自动关闭

问题：使用 ArrayList 进行频繁的插入/删除操作

// 错误的 对开头的许多插入内容不友善
List<String> list = new ArrayList<>();
list.add(0, "item"); // O(n) 操作

// 正确的 对于频繁插入的情况
List<String> list = new LinkedList<>();
list.addFirst("item"); // O(1) 操作

问题：在不需要同步的情况下同步整个方法

// 错误的 - 锁住整个方法
public synchronized void doSomething() {
    // 一些处理
    //其他一些无需加锁的缓慢操作
}

// 正确的 - 只锁需要锁的地方
public void doSomething() {
    // 其他的操作 
    synchronized(this) {
      //只有需要进行锁定的缓慢操作
    }
}