Cannot create a project in cloud

[farmaazon]

Discord username

farmaazon

What type of issue is this?

Permanent – Occurring repeatably

Is this issue blocking you from using Enso?

• Yes, I can't use Enso because of this issue.

Is this a regression?

• Yes, previous version of Enso did not have this issue.

What issue are you facing?

When I create a new project in the cloud, it loads but does not show any nodes. When I stop the project and re-run, it does not open even after long waiting (10 minutes).

Expected behaviour

I see the starting node after creating new project; running it should open it in a reasonable time.

How we can reproduce it?

No response

Screenshots or screencasts

No response

Logs

No response

Enso Version

a786ad2

Browser or standalone distribution

Standalone distribution (cloud project)

Browser Version or standalone distribution

standaolne

Operating System

Linux

Operating System Version

Garuda

Hardware you are using

No response

[PabloBuchu]

So there is bunch of errors in messages and logs from language server. @hubertp could you take a look? @somebody1234 have anything changed in communication with the server?

[hubertp]

Received InboundMessage with unknown payload type [1] looks like a culprit.

[somebody1234]

seems like this is the reason why:

• Automatic generation of the binary protocol handler in GUI #9658

[farmaazon]

seems like this is the reason why:

• Automatic generation of the binary protocol handler in GUI #9658

I'm doubtful.

The flatbuffer's format does not change between different versions of flatc - so the format emitted by code generated with never version of flatc should be happily read by code generated by older version, if the schema files were the same - and those haven't been touched from a long time.

And the fact, that the local projects are working properly seems to confirm it. Any issue with binary connection should be visible when running local projects too. But this does not happen.

[somebody1234]

ah, weird... in that case i'm not sure why payload type 1 is an error then:

enso/app/gui2/shared/binaryProtocol.ts

Line 708 in 660c5e7

INIT_SESSION_CMD = 1,

since it seems to be the session initialization payload...

[somebody1234]

so it seems line engine does not handle duplicate INIT_SESSION messages.

enso/engine/language-server/src/main/scala/org/enso/languageserver/protocol/binary/BinaryConnectionController.scala

Lines 192 to 207 in 660c5e7

	private def createRequestHandlers(
	outboundChannel: ActorRef
	): Map[InboundPayloadType, Props] = {
	Map(
	WRITE_FILE_CMD -> WriteBinaryFileHandler
	.props(requestTimeout, fileManager, outboundChannel),
	READ_FILE_CMD -> ReadBinaryFileHandler
	.props(requestTimeout, fileManager, outboundChannel),
	CHECKSUM_BYTES_CMD -> ChecksumBytesHandler
	.props(requestTimeout, fileManager, outboundChannel),
	WRITE_BYTES_CMD -> WriteBytesHandler
	.props(requestTimeout, fileManager, outboundChannel),
	READ_BYTES_CMD -> ReadBytesHandler
	.props(requestTimeout, fileManager, outboundChannel)
	)
	}

i assume then, that this is due to the same 15 second timeout issue from before?

[somebody1234]

this is also suspicious:

maybe the dashboard is starting GUI2 twice...?

[hubertp]

In my case I'm getting a blank page as well but no errors on backend. Maybe one of the console errors explains?

[somebody1234]

i assume cloud.enso.org still doesn't work as it's still using GUI1?

[hubertp]

i assume cloud.enso.org still doesn't work as it's still using GUI1?

Whaaa? Well that would explain things. But I talked to @PabloBuchu yesterday and he said it is running develop.

[somebody1234]

hmm. i guess it's running develop, but the logic to fetch GUI from S3 has not been changed - and i guess S3 has not been updated with GUI2

it's worth noting that cloud.enso.org does not work anyway (afaict), because we do not yet have the Y.js server (for syncing GUI state and text file state) running on the cloud.

[hubertp]

I'm seeing (with trace level logs) something suspicious:

May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]: [TRACE] [2024-05-02T15:40:30Z] [org.enso.librarymanager.local.DefaultLocalLibraryProvider] Local library Standard.Base not found at [***/libraries].
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]: [TRACE] [2024-05-02T15:40:30Z] [org.enso.librarymanager.local.DefaultLocalLibraryProvider] Failed to load the candidate library package description at [***/data_root].
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]: org.enso.pkg.PackageManager$PackageNotFound: The package file does not exist.
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.pkg.PackageManager.loadPackage(Package.scala:348)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.librarymanager.local.DefaultLocalLibraryProvider.$anonfun$findCandidates$2(DefaultLocalLibraryProvider.scala:79)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:178)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at java.base/java.util.Iterator.forEachRemaining(Iterator.java:133)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at java.base/java.util.Spliterators$IteratorSpliterator.forEachRemaining(Spliterators.java:1939)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:575)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at java.base/java.util.stream.AbstractPipeline.evaluateToArrayNode(AbstractPipeline.java:260)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at java.base/java.util.stream.ReferencePipeline.toArray(ReferencePipeline.java:616)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at java.base/java.util.stream.ReferencePipeline.toArray(ReferencePipeline.java:622)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at java.base/java.util.stream.ReferencePipeline.toList(ReferencePipeline.java:627)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.librarymanager.local.DefaultLocalLibraryProvider.findCandidates(DefaultLocalLibraryProvider.scala:77)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.librarymanager.local.DefaultLocalLibraryProvider.findLibraryHelper(DefaultLocalLibraryProvider.scala:39)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.librarymanager.local.DefaultLocalLibraryProvider.findLibrary(DefaultLocalLibraryProvider.scala:24)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.librarymanager.LibraryResolver.resolveLibraryVersion(LibraryResolver.scala:36)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.librarymanager.DefaultLibraryProvider.findLibrary(DefaultLibraryProvider.scala:52)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.interpreter.runtime.DefaultPackageRepository.ensurePackageIsLoaded(DefaultPackageRepository.scala:411)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.compiler.phase.ImportResolverForIR.loadLibraryModule(ImportResolverForIR.java:124)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.compiler.phase.ImportResolverForIR.loadLibraryModule(ImportResolverForIR.java:23)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.compiler.phase.ImportResolverAlgorithm.tryResolveImportNew(ImportResolverAlgorithm.java:141)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.compiler.phase.ImportResolverAlgorithm.tryResolveImport(ImportResolverAlgorithm.java:72)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.compiler.phase.ImportResolver.$anonfun$mapImports$3(ImportResolver.scala:74)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/scala.collection.immutable.List.map(List.scala:246)
May 02 15:40:30 ip-172-31-0-127.eu-west-1.compute.internal enso_runtime[2573]:         at org.enso.runtime/org.enso.compiler.phase.ImportResolver.analyzeModule$1(ImportResolver.scala:72)

As if all libraries were gone

[hubertp]

Actually that doesn't seem to be the cause of the problem. I will need to investigate why it happens in the first place but it seems to recover from this problem.

[hubertp]

Not sure how relevant that is but why is GUI reporting a wrong version in cloud? I thought it's using latest nightly?

[jdunkerley]

hmm. i guess it's running develop, but the logic to fetch GUI from S3 has not been changed - and i guess S3 has not been updated with GUI2

it's worth noting that cloud.enso.org does not work anyway (afaict), because we do not yet have the Y.js server (for syncing GUI state and text file state) running on the cloud.

We have had the GUI2 running with a cloud backend in electron. Yes we have to run the y.js server locally but it was working.

[somebody1234]

yup - by "cloud.enso.org" i mean specifically the website hosted at cloud.enso.org.

when we run through electron (and on the browser of the electron server!) i believe we do use the local version of the GUI, as the check for whether we need to download the GUI, is determined by whether the Local Backend (the Project Manager backend) is supported

[hubertp]

So I have a fix for the timeout that is being reported when using electron app and connection to the cloud. The issue is basically... weak hardware. On my machine first compilation takes max 3-4 seconds on a bad day. In the cloud setup it takes at least 25 seconds alone. Given that we have timeouts for serving API requests set to 5 seconds, the problem becomes rather common.

When running via browser, I believe it is not running the latest GUI? At least the type of requests seem a bit outdated and different from what electron (nightly) is doing.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2024-05-03):

Progress: Paused work on #9736 to investigate cloud issues. Looks like slow compilations are delaying handling of requests leading to timeouts. Added workaround in multiple handlers so that we don't return timeout immediately. It should be finished by 2024-05-06.

Next Day: Next day I will be working on the #9789 task. Continue the investigation. Figure out if we can profile the startup to find the root cause.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2024-05-08):

Progress: Continued an effort to pinpoint the change that broke cloud support. Looks like it is mostly cloud-setup dependent as sometimes gui build works and sometimes not. Waiting on profiling data and more logs info to confirm. In the meantime continued my work on #9736, trying to get a draft PR out. It should be finished by 2024-05-09.

Next Day: Next day I will be working on the #9789 task. Continue the investigation.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2024-05-09):

Progress: Draft PR for #9736, waiting on the option to gather cloud profile data. It should be finished by 2024-05-09.

Next Day: Next day I will be working on the #9789 task. Continue the investigation.

[enso-bot]

Hubert Plociniczak reports a new 🔴 DELAY for the provided date (2024-05-10):

Summary: There is 6 days delay in implementation of the Cannot create a project in cloud (#9789) task.
It will cause 0 days delay for the delivery of this weekly plan.

Delay Cause: Still haven't figured out why cloud setup affects performance. Unable to reproduce problems locally.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2024-05-10):

Progress: Analyzing profiling data, adding more logs, reducing potential bottlenecks to unclog cloud setup (#9927, #9915) It should be finished by 2024-05-15.

Next Day: Next day I will be working on the #9789 task. Continue the investigation.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2024-05-13):

Progress: Addressing review on PRs, still trying to investigate bottlenecks based on the logs and profiling data. It should be finished by 2024-05-15.

Next Day: Next day I will be working on the #9789 task. Continue the investigation.

[hubertp]

Regarding websocket being randomly closed on startup I was able to reproduce the problem by adding a simple Thread.sleep in https://github.com/enso-org/enso/blob/develop/engine/language-server/src/main/scala/org/enso/languageserver/http/server/BinaryWebSocketServer.scala#L71. Except in my case in the logs I was able to see that the connection was being closed.

The conclusion is that I believe the server is simply overloaded on startup and slow to respond to a new websocket connection request, leading to some kind of timeout on the GUI side. On a subsequent try from GUI it typically connects without any problems so the problem can be more or less ignored.

The performance in the cloud, given the current resources, is still unsatisfactory and can lead to such random failures. We don't want to "recover" from such issues, we simply don't want to have them to appear in the first place.

GitHub

enso/engine/language-server/src/main/scala/org/enso/languageserver/http/server/BinaryWebSocketServer.scala at develop · enso-org/enso

Hybrid visual and textual functional programming. Contribute to enso-org/enso development by creating an account on GitHub.

[hubertp]

I finally managed to get hold of profiling data from a low spec machine that more closely resembles users' and current cloud spec.
Uploading profiling.npss.txt…
It looks like a considerable amount of time is spent in jackson serde.

[enso-bot]

Hubert Plociniczak reports a new 🔴 DELAY for today (2024-05-20):

Summary: There is 7 days delay in implementation of the Cannot create a project in cloud (#9789) task.
It will cause 0 days delay for the delivery of this weekly plan.

Delay Cause: Regressions when testing on low spec machine. Temporarily moved on to work on other issues.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for today (2024-05-20):

Progress: Finding culprit change for #9993. Continued work on replacing jackson to potentially speedup startup, based on the collected profiling data. Devising plan on further improvements to startup. It should be finished by 2024-05-22.

Next Day: Next day I will be working on the #9789 task. Continue the investigation.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2024-05-16):

Progress: Not much progress with gathering profiling data from cloud. Switched to a local low-spec machine. It should be finished by 2024-05-22.

Next Day: Next day I will be working on the #9789 task. Continue the investigation.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2024-05-17):

Progress: Added profiling option to AppImage so that profiling data can be collected from a local setup. Found a recent regression on startup and narrowed it down to a range of commits. Analyzing collected data and trying to come up with some perf improvements. It should be finished by 2024-05-22.

Next Day: Next day I will be working on the #9789 task. Continue the investigation.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for yesterday (2024-05-21):

Progress: Still tinkering with jackson replacement. Dealing with non-deterministic bug in deserialization in jsoniter. Will file a bug upstream. It should be finished by 2024-05-22.

Next Day: Next day I will be working on the #9789 task. Continue the investigation.

[enso-bot]

Hubert Plociniczak reports a new 🔴 DELAY for the provided date (2024-06-06):

Summary: There is 19 days delay in implementation of the Cannot create a project in cloud (#9789) task.
It will cause 0 days delay for the delivery of this weekly plan.

Delay Cause: Draft PR was parked until refactoring of ModuleScope was finished.

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2024-06-06):

Progress: Bringing old PR up-to-date. Trying workarounds for some encoding issues with Option values. Initial performance results are very promising. It should be finished by 2024-06-10.

Next Day: Next day I will be working on the #9789 task. Continue integrating new JSON serde

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2024-06-07):

Progress: Testing the final version of PR. Confirmed performance results. Removing jackson whenever possible. Added a workaround for Option values that caused issues when deserializing them. It should be finished by 2024-06-10.

Next Day: Next day I will be working on the #9789 task. Deal with licensing, finish removing jackson

[enso-bot]

Hubert Plociniczak reports a new STANDUP for the provided date (2024-06-10):

Progress: Finished replacement of jackson to jsoniter. Started looking into performance issues in the cloud #10231. Profiling startup. It should be finished by 2024-06-10.

Next Day: Next day I will be working on the #10231 task. Continue investigating startup issues

[hubertp]

This is currently blocked on Ydoc integration in the cloud.

[hubertp]

Partially related: #9993 (comment) Blocked by #10495