:tophat: Hello. I'm curious what's the `Loading Ap...

# apollo-kotlin

[wasyl]

🎩 Hello. I'm curious what's the Loading Apollo Configuration step doing when I run my IDE? I almost reported an issue that it's stuck, but it turns out by the time I submitted it this loading completed, so it doesn't look like a bug really. But it consistently takes couple of minutes and prevents IDE from indexing, so it's a bit cumbersome

[bod]

Hi! 👋

This step allows the plugin to get information from Gradle, which is then used by the GraphQL plugin to know where your operations and schemas are.

Unfortunately this cannot be done in one go and must be done module per module, which if you have a lot can take a while.

However this shouldn't block indexing (I'll have a look to be sure).

[wasyl]

Ah, well we have ~400 modules, so it might be that 😕 And as far as I see I can resume indexing, it's just paused by default I suppose, probably because the project is still importing

[wasyl]

Is it possible that project import waits for this action, then?

[bod]

(it only considers modules where the Apollo Kotlin Gradle plugin is applied)

[wasyl]

Okay, that should be just one module 🙂

[bod]

Is it possible that project import waits for this action, then?

That might be it, but not sure 🙂 Not on purpose in any case 🙂

[bod]

Okay, that should be just one module

oh... then 2 minutes seems a bit long! On the other hand, no matter what, the Gradle configuration of your whole project needs to initialize. Basically the same as if you run a task in one of the modules.

[wasyl]

I see, that makes sense. I haven't timed it exactly so I might be just impatient 🙂 I'll do that next time

[wasyl]

And then is there a good way to verify if this actions blocks import (or anything else)? 🤔 It definitely looks like it, but I'm not that familiar with how IJ plugins work

[bod]

I'm not completely sure 😅 What I'll do to check is I'm going to make a fake task that never ends - should be obvious if that blocks indexing or anything else

[bod]

(by the way in the meantime if this is too annoying you can also disable this feature in the settings : "Contribute configuration to the GraphQL plugin" in Languages & Frameworks | GraphQL | Apollo Kotlin)

[bod]

if you have only 1 AK module it shouldn't change anything 🙂 (well that's not true if you have 1 module but several services)

[bod]

from what I can tell, the infinite task doesn't seem to block indexing in my case

[wasyl]

and what about project import? 🤔

[wasyl]

Hm, basically the screenshot I showed above is what I saw for quite some time, after opening a project. Perhaps IDE's Gradle stuff was waiting for Apollo's Gradle stuff so as not to start multiple daemons?

[bod]

ooh ok maybe my test is flawed indeed

[bod]

in theory the plugin doesn't do anything before indexing is finished (and so that should be after project import). But maybe there's an issue around this area.

[wasyl]

Thread.sleep(10000), done 👌

[bod]

hahaha why not 🙂

[agrosner]

+1 to that. We have similar amount of modules, have like 20ish Apollo modules and 1 schema module.

[bod]

@agrosner do you mean +1 to the fact that this blocks other IDE tasks?

[agrosner]

Sorry I wasn’t specific . I’ve observed the long load time, but haven’t noticed it stop indexing from happening. I’ll let you know if I notice same thing

[bod]

Thanks! Yeah long loading time is expected, but it impacting/delaying other parts of the IDE isn't.

[bod]

All right from what I can tell, the task doesn't block other tasks. I'm guessing in your screenshot, the paused tasks are paused because of the "Importing Gradle Project" one.

[bod]

There's something a bit annoying though - at the end of the "Importing Gradle Project" task, the "Loading Apollo Kotlin configuration" one will be restarted. That's because it's triggered by "gradle sync" events, which can happen several times when opening a project.

[bod]

so it can run twice whereas once would have been enough... not sure if I can find a way to improve that

[wasyl]

👍 I'll play with this later, see how long Importing Gradle Project alone takes (maybe it's some problem in recent AS Canary versions) with Apollo plugin disabled, and with it enabled.

Does AK plugin emit any logs that I can refer to when looking for timings/how many times the loading happens? I'll also try capturing startup performance snapshot if I remember how to do that 😄

[bod]

there are logs but they need to be manually enabled:

Help | Diagnostic Tools | Debug Log Settings | add Apollo

[wasyl]

Here's idea.log grepped by Apollo, I observed the same long times

2023-06-28 20:20:27,488 [    182]   INFO - #c.i.i.p.PluginManager - Loaded custom plugins: macOS Keymap (231.7515.9), GraphQL (4.0.1), .ignore (4.5.1), GitHub Copilot (1.2.9.2684), Kotest (1.3.69-IC-2023.1), Apollo GraphQL (4.0.0-alpha.1), ADB Idea (1.6.11), Kotlin Fill Class (1.0.20), Kotlin (231-1.9.0-RC-release-336-AS8770.65), Key Promoter X (2023.1.0), String Manipulation (9.9.0)
2023-06-28 20:20:28,275 [    969]   INFO - #c.i.d.DebugLogManager - Set DEBUG for the following categories: Apollo, #Apollo
2023-06-28 20:20:30,710 [   3404]   FINE - Apollo - ApolloProjectManagerListener projectOpened
2023-06-28 20:20:36,531 [   9225]   FINE - Apollo - ApolloProjectServiceImpl <init> - project=talent-app
2023-06-28 20:20:36,531 [   9225]   FINE - Apollo - ApolloProjectServiceImpl onLibrariesChanged
2023-06-28 20:20:36,687 [   9381]   FINE - Apollo - ApolloProjectServiceImpl onLibrariesChanged - isApolloAndroid2Project=false isApolloKotlin3Project=true
2023-06-28 20:20:36,688 [   9382]   FINE - Apollo - ApolloProjectServiceImpl startObserveLibraries
2023-06-28 20:20:36,689 [   9383]   FINE - Apollo - ApolloProjectManagerListener projectOpened$lambda$0 - isApolloKotlin3Project=true
2023-06-28 20:20:36,691 [   9385]   FINE - Apollo - ApolloCodegenService <init> - project=talent-app
2023-06-28 20:20:36,695 [   9389]   FINE - Apollo - ApolloCodegenService startObserveDocumentChanges
2023-06-28 20:20:36,696 [   9390]   FINE - Apollo - ApolloCodegenService startObserveFileEditorChanges
2023-06-28 20:20:36,696 [   9390]   FINE - Apollo - ApolloCodegenService startContinuousGradleCodegen
2023-06-28 20:20:36,697 [   9391]   FINE - Apollo - ApolloCodegenService startObserveGradleHasSynced
2023-06-28 20:20:36,698 [   9392]   FINE - Apollo - ApolloCodegenService startObserveApolloProject
2023-06-28 20:20:36,698 [   9392]   FINE - Apollo - ApolloCodegenService startObservingSettings
2023-06-28 20:20:36,704 [   9398]   FINE - Apollo - GradleToolingModelService <init> - project=talent-app
2023-06-28 20:20:36,704 [   9398]   FINE - Apollo - GradleToolingModelService startObserveApolloProject
2023-06-28 20:20:36,704 [   9398]   FINE - Apollo - GradleToolingModelService startOrStopObserveGradleHasSynced
2023-06-28 20:20:36,704 [   9398]   FINE - Apollo - GradleToolingModelService startObserveGradleHasSynced
2023-06-28 20:20:36,704 [   9398]   FINE - Apollo - GradleToolingModelService startOrAbortFetchToolingModels
2023-06-28 20:20:36,704 [   9398]   FINE - Apollo - GradleToolingModelService abortFetchToolingModels
2023-06-28 20:20:36,705 [   9399]   FINE - Apollo - GradleToolingModelService fetchToolingModels
2023-06-28 20:20:36,710 [   9404]   FINE - Apollo - GradleToolingModelService startObservingSettings
2023-06-28 20:20:36,710 [   9404]   FINE - Apollo - GraphQLConfigService <init> - project=talent-app
2023-06-28 20:20:36,720 [   9414]   FINE - Apollo - ApolloCodegenService$startContinuousGradleCodegen$1$1 invoke - Start Gradle
2023-06-28 20:20:36,727 [   9421]   FINE - Apollo - GradleToolingModelService$FetchToolingModelsTask$run$rootGradleProject$1 invoke - Fetch Gradle project model
2023-06-28 20:20:37,721 [  10415]   FINE - Apollo - ApolloGraphQLConfigContributor contributeConfigs
2023-06-28 20:20:39,072 [  11766]   FINE - Apollo - ApolloCodegenService$startContinuousGradleCodegen$1$1 invoke$lambda$2 - Gradle build started
2023-06-28 20:20:43,369 [  16063]   FINE - Apollo - ApolloProjectServiceImpl$startObserveLibraries$1 rootsChanged - event=com.intellij.openapi.roots.impl.ModuleRootEventImpl[source=Project(name=talent-app, containerState=COMPONENT_CREATED, componentStore=/home/wasyl/projects/toptal/talent-app)]
2023-06-28 20:20:43,369 [  16063]   FINE - Apollo - ApolloProjectServiceImpl onLibrariesChanged
2023-06-28 20:20:43,546 [  16240]   FINE - Apollo - ApolloProjectServiceImpl onLibrariesChanged - isApolloAndroid2Project=false isApolloKotlin3Project=true
2023-06-28 20:21:29,319 [  62013]   FINE - Apollo - ApolloGraphQLConfigContributor contributeConfigs
2023-06-28 20:26:37,428 [ 370122]   FINE - Apollo - GradleToolingModelService$FetchToolingModelsTask run - allApolloGradleProjects=[]
2023-06-28 20:26:37,428 [ 370122]   FINE - Apollo - GradleToolingModelService$FetchToolingModelsTask run - allToolingModels=[]
2023-06-28 20:26:37,429 [ 370123]   FINE - Apollo - GradleToolingModelService computeGraphQLProjectFiles - graphQLProjectFiles=[]
2023-06-28 20:26:37,430 [ 370124]   FINE - Apollo - GraphQLConfigService$1 projectFilesAvailable - Calling scheduleConfigurationReload
2023-06-28 20:26:37,931 [ 370625]   FINE - Apollo - ApolloGraphQLConfigContributor contributeConfigs
2023-06-28 20:26:39,968 [ 372662]   FINE - Apollo - ApolloCodegenService$startContinuousGradleCodegen$1$1 invoke$lambda$2 - Gradle build success, marking generated source roots as dirty
2023-06-28 20:26:39,973 [ 372667]   FINE - Apollo - ApolloCodegenService$startContinuousGradleCodegen$1$1 invoke$lambda$2 - Mark dirty [file:///home/wasyl/projects/toptal/talent-app/data/networking/graphql/generated-models/build/generated/source/apollo/platform]
2023-06-28 20:26:54,865 [ 387559]   FINE - Apollo - GradleListener onSuccess
2023-06-28 20:26:54,866 [ 387560]   FINE - Apollo - ApolloCodegenService$startObserveGradleHasSynced$1 gradleHasSynced
2023-06-28 20:26:54,866 [ 387560]   FINE - Apollo - ApolloCodegenService stopContinuousGradleCodegen
2023-06-28 20:26:54,867 [ 387561]   FINE - Apollo - ApolloCodegenService startContinuousGradleCodegen
2023-06-28 20:26:54,868 [ 387562]   FINE - Apollo - GradleToolingModelService$startObserveGradleHasSynced$1 gradleHasSynced
2023-06-28 20:26:54,868 [ 387562]   FINE - Apollo - GradleToolingModelService startOrAbortFetchToolingModels
2023-06-28 20:26:54,868 [ 387562]   FINE - Apollo - GradleToolingModelService abortFetchToolingModels
2023-06-28 20:26:54,868 [ 387562]   FINE - Apollo - GradleToolingModelService fetchToolingModels
2023-06-28 20:26:54,870 [ 387564]   FINE - Apollo - GradleToolingModelService$FetchToolingModelsTask$run$rootGradleProject$1 invoke - Fetch Gradle project model
2023-06-28 20:26:54,886 [ 387580]   FINE - Apollo - ApolloCodegenService$startContinuousGradleCodegen$1$1 invoke - Gradle execution finished
2023-06-28 20:26:54,886 [ 387580]   FINE - Apollo - ApolloCodegenService$startContinuousGradleCodegen$1$1 invoke - Start Gradle
2023-06-28 20:26:54,898 [ 387592]   FINE - Apollo - ApolloCodegenService$startContinuousGradleCodegen$1$1 invoke$lambda$2 - Gradle build started
2023-06-28 20:26:55,432 [ 388126]   FINE - Apollo - ApolloCodegenService$startContinuousGradleCodegen$1$1 invoke$lambda$2 - Gradle build success, marking generated source roots as dirty
2023-06-28 20:26:55,435 [ 388129]   FINE - Apollo - ApolloCodegenService$startContinuousGradleCodegen$1$1 invoke$lambda$2 - Mark dirty [file:///home/wasyl/projects/toptal/talent-app/data/networking/graphql/generated-models/build/generated/source/apollo/platform]
2023-06-28 20:27:02,932 [ 395626]   FINE - Apollo - GradleToolingModelService$FetchToolingModelsTask run - allApolloGradleProjects=[]
2023-06-28 20:27:02,932 [ 395626]   FINE - Apollo - GradleToolingModelService$FetchToolingModelsTask run - allToolingModels=[]
2023-06-28 20:27:02,933 [ 395627]   FINE - Apollo - GradleToolingModelService computeGraphQLProjectFiles - graphQLProjectFiles=[]
2023-06-28 20:27:02,933 [ 395627]   FINE - Apollo - GraphQLConfigService$1 projectFilesAvailable - Calling scheduleConfigurationReload
2023-06-28 20:27:03,544 [ 396238]   FINE - Apollo - ApolloProjectServiceImpl$startObserveLibraries$1 rootsChanged - event=com.intellij.openapi.roots.impl.ModuleRootEventImpl[source=Project(name=talent-app, containerState=COMPONENT_CREATED, componentStore=/home/wasyl/projects/toptal/talent-app)]
2023-06-28 20:27:03,545 [ 396239]   FINE - Apollo - ApolloProjectServiceImpl onLibrariesChanged
2023-06-28 20:27:03,620 [ 396314]   FINE - Apollo - ApolloProjectServiceImpl onLibrariesChanged - isApolloAndroid2Project=false isApolloKotlin3Project=true
2023-06-28 20:27:07,934 [ 400628]   FINE - Apollo - ApolloGraphQLConfigContributor contributeConfigs
2023-06-28 20:27:07,934 [ 400628]   FINE - Apollo - ApolloGraphQLConfigContributor contributeConfigs
2023-06-28 20:27:37,152 [ 429846]   FINE - Apollo - ApolloProjectServiceImpl$startObserveLibraries$1 rootsChanged - event=com.intellij.openapi.roots.impl.ModuleRootEventImpl[source=Project(name=talent-app, containerState=COMPONENT_CREATED, componentStore=/home/wasyl/projects/toptal/talent-app)]
2023-06-28 20:27:37,152 [ 429846]   FINE - Apollo - ApolloProjectServiceImpl onLibrariesChanged
2023-06-28 20:27:37,217 [ 429911]   FINE - Apollo - ApolloProjectServiceImpl onLibrariesChanged - isApolloAndroid2Project=false isApolloKotlin3Project=true
2023-06-28 20:27:37,944 [ 430638]   FINE - Apollo - ApolloCodegenService$startObserveFileEditorChanges$1 selectionChanged - file:///home/wasyl/.cache/Google/AndroidStudioPreview2023.1/log/idea.log
2023-06-28 20:27:38,436 [ 431130]   FINE - Apollo - ApolloGraphQLConfigContributor contributeConfigs
2023-06-28 20:31:31,532 [ 664226]   FINE - Apollo - ApolloCodegenService$startObserveFileEditorChanges$1 selectionChanged
2023-06-28 20:31:31,540 [ 664234]   FINE - Apollo - ApolloCodegenService$startObserveFileEditorChanges$1 selectionChanged - file:///home/wasyl/.config/Google/AndroidStudioPreview2023.1/scratches/scratch_8.txt

[wasyl]

And I do see some weird timings here, one log at 20:21 and another at 20:26

[wasyl]

(I think the last jump to :31 is already after stuff worked and I got to analyze logs)

[wasyl]

logs between the biggest gap

[bod]

Thanks for the logs!

So the interesting bit is fetchToolingModels, which happened twice in your case: 1/ after the project opened at 202036,705 2/ after a Gradle sync finished at 202654,868

Your logs reminded me of something that slipped my mind: for this to work, the project needs to use Apollo Kotlin 4. This is because this require collaboration from the Gradle plugin that isn't in 3.x. That's why you see allApolloGradleProjects=[] in the logs.

I think I will disable this fetching if the Apollo lib version is < 4, to avoid any confusion (and unnecessary Gradle runs).