SpringBoot、GraphQL 性能泄露

Posted 2023-03-08

【中文标题】SpringBoot、GraphQL 性能泄露

【英文标题】：SpringBoot, GraphQL performance leak

【发布时间】：2020-10-10 00:11:53

【问题描述】：

Given 是一个托管 graphQL 服务器 的 SpringBoot 应用程序。它使用了许多DataLoaders，它们本身似乎表现良好，但我注意到与它们相关（或介于两者之间）的非常大性能泄漏我无法清楚地缩小范围 - 但可以衡量它。

问题

某些 (UI) 客户端从服务调用 graphQL API 的 查询，这将触发对 x 元素 (x > 10_000) 的提取。 GraphQLQueryResolver 在 SpringBoot 服务中被调用，它获取 x 元素。 调用字段 getter 的函数，从加载的 DataLoader<K,T> 返回 CompletionStage<T> 需要很长时间的事情 DataLoader<K,T> 实现类使用批量键调用并返回结果。

示例日志如下所示：

2020-06-19T18:25:14.196Z [http-nio-80-exec-10] ~ Shopping ~ INFO  ~ It took |> PT0.095S <| for 'orders query with filter:[OrderFilter(col=createdAt, operator=BETWEEN, value=2020-01-05T00:00:00Z AND 2020-05-31T00:00:00Z)]'
2020-06-19T18:25:18.686Z [DefaultDispatcher-worker-6] ~ Shopping ~ INFO  ~ It took |> PT0.001S <| for 'orderKpiDataLoader' (PT0.000000095S on average for #10476 executions)
2020-06-19T18:25:23.229Z [DefaultDispatcher-worker-19] ~ Shopping ~ INFO  ~ Start 'priceForOrderReferences'
2020-06-19T18:25:24.840Z [DefaultDispatcher-worker-41] ~ Shopping ~ WARN  ~ It took |> PT1.613S <| for 'orderDepositDataLoader' (PT0.00015397S on average for #10476 executions)

日志案例说明：

18:25:14.196 ：调用“带过滤器的订单查询”并在 95 毫秒内返回 #10476 个元素 + 4.49 S ：它的所有字段“orderKpi”都是从它们的DataLoader返回的。创建并返回它们需要 1 毫秒。 + 4.54 S : "orderKpi" 的 "priceForOrderReferences" 字段通过它自己的 DataLoader 加载。创建并返回它们需要 1.613 秒。

解决问题

在调用 DataLoader 之间的时间会发生什么？ （那些 +4.49S 和 +4.54S） 如何减少它？

我所做的事情和我的假设

我尝试将 DataLoaders 设为单例，因为我认为创建对象需要很长时间 - 这不是问题。 我尝试通过覆盖批处理大小来引入手动批处理 - 它稍微减少了时间，但增加了整体运行时间（不同的批处理大小对不同的元素大小的工作方式不同） 由于批处理减少了时间（很少），我假设性能泄漏来自“收集”元素键以创建一个列表并将它们传递给 DataLoader。 我还手动测量了每个项目的平均性能泄漏时间，它似乎总是每个元素约 1 毫秒。 我没有找到任何代码部分如何收集它们，或者如何自己覆盖它。

新信息：

我尝试了不同的数据加载器库，例如：

<dependency>
    <groupId>com.graphql-java-kickstart</groupId>
    <artifactId>graphql-kickstart-spring-boot-starter-tools</artifactId>
    <version>7.0.1</version>
</dependency>

和

<dependency>
    <groupId>com.graphql-java-kickstart</groupId>
    <artifactId>graphql-java-tools</artifactId>
    <version>6.0.2</version>
</dependency>

并且还禁用了缓存 - 仍然是相同的结果。我放了更多日志（当然要小心，所以它们本身不会降低性能），我的新线索是，graphql 库是问题本身，而不是 DataLoader。在一种情况下，我删除了一个字段的 DataLoader - 在调用它之前花费了相同的时间！

统计数据

春天

<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-parent</artifactId>
<version>2.1.7.RELEASE</version>

我的 graphQL 依赖项

<dependency>
    <groupId>com.graphql-java-kickstart</groupId>
    <artifactId>graphql-spring-boot-starter</artifactId>
    <version>7.0.1</version>
</dependency>
<dependency>
    <groupId>com.apollographql.federation</groupId>
    <artifactId>federation-graphql-java-support</artifactId>
    <version>0.4.1</version>
</dependency>
<dependency>
    <groupId>com.graphql-java-kickstart</groupId>
    <artifactId>playground-spring-boot-starter</artifactId>
    <version>7.0.1</version>
</dependency>
<dependency>
    <groupId>com.graphql-java</groupId>
    <artifactId>graphql-java-extended-scalars</artifactId>
    <version>1.0.1</version>
</dependency>
<dependency>
    <groupId>com.graphql-java</groupId>
    <artifactId>java-dataloader</artifactId>
    <version>2.2.3</version>
</dependency>

数据加载器

所有 DataLoader 都实现了这个抽象：

import com.smark.shopping.utils.FunctionPerformance
import kotlinx.coroutines.CoroutineScope
import kotlinx.coroutines.Dispatchers
import kotlinx.coroutines.future.future
import org.dataloader.DataLoader

private val dataLoaderSingleScopeIO = CoroutineScope(Dispatchers.IO)

interface DataLoaderEntryInterface<T, R> 
    val key: String
    val dataLoader: DataLoader<T, R>


abstract class DataLoaderEntryAbstract<T, R>(
    override val key: String,
    private val loader: suspend (List<T>) -> List<R>
) : DataLoaderEntryInterface<T, R> 

    private val performance = FunctionPerformance()

    override val dataLoader: DataLoader<T, R>
        get() = DataLoader.newDataLoader  ids ->
            dataLoaderSingleScopeIO.future 
                performance.executeMeasuringSuspend(key, ids.size)  loader(ids) 
            
        


@Component
class DataLoaderOrderDeposit(private val orderTotalPriceService: OrderTotalPriceService) : DataLoaderEntryAbstract<Int, Int>(
    key = ORDER_DEPOSIT_DATA_LOADER,
    loader =  orderReferences -> orderTotalPriceService.priceForOrderReferences(orderReferences).map  it.deposit  
)

解析器

@Component
class OrderResolver : GraphQLResolver<ShopOrder> 

     fun kpi(shopOrder: ShopOrder, dfe: DataFetchingEnvironment): CompletionStage<OrderKpi> =
        DataLoaderFuture<OrderKpi>(dfe, ORDER_KPI_DATA_LOADER).loadBy(shopOrder)


@Component
class OrderKpiResolver : GraphQLResolver<OrderKpi> 

    fun deposit(orderKpi: OrderKpi, dfe: DataFetchingEnvironment): CompletionStage<Int> =
        dfe.getDataLoader<Int, Int>(ORDER_DEPOSIT_DATA_LOADER).load(orderKpi.orderReference)

上下文构建器

@Component
class CustomGraphQLContextBuilder(
    private val dataLoadersSummelsarium: DataLoadersSummelsarium
) : GraphQLServletContextBuilder 

    override fun build(req: HttpServletRequest, response: HttpServletResponse): GraphQLContext =
        DefaultGraphQLServletContext.createServletContext(buildDataLoaderRegistry(), null)
                .with(req)
                .with(response)
                .build()

    override fun build(session: Session, request: HandshakeRequest): GraphQLContext =
        DefaultGraphQLWebSocketContext.createWebSocketContext(buildDataLoaderRegistry(), null)
                .with(session)
                .with(request)
                .build()

    override fun build(): GraphQLContext = DefaultGraphQLContext(buildDataLoaderRegistry(), null)

    private fun buildDataLoaderRegistry(): DataLoaderRegistry =
        DataLoaderRegistry().apply 
            dataLoadersSummelsarium.dataLoaders().forEach  register(it.key, it.dataLoader) 
        

【问题讨论】：

性能泄漏？ Slowdown 可能是一个更好的词（leak 更常与 resource 相关联，如在内存中）。

如果有某种小型的、独立的示例可以重现该问题，那么回答起来会容易得多。现在你有很多堆栈要查看，而问题只涉及其中的一部分。

@tucuxi 是的，你是对的。赏金结束后我会改名。考虑到“要查看大量堆栈” - 这已经是一个简化版本。如果我遗漏更多，它可能不再代表我的情况 - 我不知道可以遗漏什么，因为我不知道什么是错的。

分析器还可以帮助您查明所花费的时间，而无需进行大量手动检测。

【参考方案1】：

我自己的解决方案：

---

在调用 DataLoader 之间会发生什么？ （那些 +4.49S & +4.54S)

我仍然不确定究竟是什么减慢了它的速度，但这似乎是 graphql-java 依赖项的问题。在 graphql java-script 实现中执行类似查询时，时间延迟约为 60 毫秒。

我怎样才能减少它？

我找到了good article concerning graphQL performance，我在其中接受了提前加载更多数据的建议，在顶层。通过这种方式，还可以创建自定义类来保存更多数据，并可以减少较低级别的冗余存储库路径。 为避免 DataLoader 在执行函数之前等待“收集”键的时间，您可以选择特定路径到 look-ahead 并自己执行加载器 - 在上层。 玩转不同 DataLoader 的批处理大小

如果你想简化答案，它可能是：“如果你想快，就不要深入”。

---

我仍然愿意接受其他解决方案。