appsmithorg / appsmith

Platform to build admin panels, internal tools, and dashboards. Integrates with 25+ databases and any API.
https://www.appsmith.com
Apache License 2.0
34.7k stars 3.75k forks source link

[Bug]: git operations very slow and time out #35644

Open naptha77 opened 3 months ago

naptha77 commented 3 months ago

Description

I have a self hosted appsmith instance with docker. Git integration has been working for weeks but now fails when I try to commit changes.

The git operation http://localhost/api/v1/git/status/app/668de___c6837?compareRemote=true times out after 2 minutes. The operation before that, http://localhost/api/v1/git/auto-commit/app/668___837?branchName=main works but takes 70 seconds to run.

This was working a week ago and nothing has changed. I had exactly the same issue before - it would work for weeks, then intermittently fail, then eventually fail every time. My solution was to build a new docker image and then import my project, which I'd rather not do obviously.

It may be related to having the appsmith editor open in multiple browser tabs at the same time. I was careful not to do that with this new docker image, but did it before I was having the issues.

On the previous version of appsmith it said it failed to acquire a git lock, whereas now it just times out

My host is a Windows VM which has 20GB of RAM and 16 vCPU's. I've never had any other performance issues or timeouts - it's just related to git which has always been slow.

Relevant logs below.

2024-08-13 08:00:54 backend stdout | [2024-08-13 00:00:54,165] requestId=51e7f43d-4784-4479-9154-80bcfdbdcbf0 userEmail=mic11@gmail.com traceId= spanId= - Git command status is trying to acquire the lock for application id 668de550f3f42c094b3c6837 2024-08-13 08:01:00 backend stdout | [2024-08-13 00:01:00,197] requestId=51e7f43d-4784-4479-9154-80bcfdbdcbf0 userEmail=mic11@gmail.com traceId= spanId= - Execute time: JGIT git_fetch, appId 668de550f3f42c094b3c6837, Time elapsed: 6023ms 2024-08-13 08:01:27 backend stdout | [2024-08-13 00:01:27,351] requestId=51e7f43d-4784-4479-9154-80bcfdbdcbf0 userEmail=mic_11@gmail.com traceId= spanId= - Execute time: JGIT git_reset, appId 668de550f3f42c094b3c6837, Time elapsed: 33122ms 2024-08-13 08:01:27 backend stdout | [2024-08-13 00:01:27,455] requestId=51e7f43d-4784-4479-9154-80bcfdbdcbf0 userEmail=mic____11@gmail.com traceId= spanId= - boundedElastic-30: Switching to the branch main 2024-08-13 08:01:58 backend stdout | [2024-08-13 00:01:58,169] requestId=51e7f43d-4784-4479-9154-80bcfdbdcbf0 userEmail=mic11@gmail.com traceId= spanId= - Execute time: JGIT git_reset, appId 668de550f3f42c094b3c6837, Time elapsed: 30665ms 2024-08-13 08:02:13 backend stdout | [2024-08-13 00:02:13,836] requestId=51e7f43d-4784-4479-9154-80bcfdbdcbf0 userEmail=mic11@gmail.com traceId= spanId= - Execute time: FS application save, Time elapsed: 79661ms 2024-08-13 08:02:13 backend stdout | [2024-08-13 00:02:13,933] requestId=51e7f43d-4784-4479-9154-80bcfdbdcbf0 userEmail=mic11@gmail.com traceId= spanId= - boundedElastic-30: Get status for repo /appsmith-stacks/git-storage/668de202f3f42c094b3c6769/668de550f3f42c094b3c6837/amazon-appsmith, branch main 2024-08-13 08:03:11 backend stdout | [2024-08-13 00:03:11,202] requestId=51e7f43d-4784-4479-9154-80bcfdbdcbf0 userEmail=mic_____11@gmail.com traceId= spanId= - Execute time: JGIT git_reset, appId 668de550f3f42c094b3c6837, Time elapsed: 40090ms

Steps To Reproduce

  1. Open new appsmith instance, connect to git
  2. Perform commits as normal -this should work
  3. (Possibly) open multiple edit instances at the same time
  4. Attempt to commit changes. Operation times out

Public Sample App

No response

Environment

Production

Severity

High (Blocker to building or releasing)

Issue video log

https://www.loom.com/share/329acf49732349e5beb854914f3c3e8c?sid=8daadb90-84b2-41c5-932c-1e28023da9fb

Version

Self hosted 1.30

infinitetrooper commented 3 months ago

cc: @nidhi-nair - is it possible to debug with the info provided?

nidhi-nair commented 3 months ago

From the timestamps in the logs, it looks like the git reset and git save operations are taking a really long time. The lock acquisition went through so this is not an issue with parallel usage, I'm inclined to think that the application has grown to be that large over time.

@naptha77 would you be able to share the size of your repository? I am also sharing a command for total number of files within. Please execute the following inside the repository directory:

du -sh
find . -type f -not -path "./.git/*" | wc -l
naptha77 commented 3 months ago

@nidhi-nair Those commands returned 1.4G and 41451

My actual repo is only 673 KB according to github. I cloned locally and it says there are 565 files, total 1.65 MB

So I'm a bit confused - the repo is very small, but the container has some large files in it. I would have thought they'd all be ignored and the git commands would still be quick.

These are the largest files in my container. Can any of them be purged to speed up git operations? Git operations have always taken a long time in appsmith since I started with it.

1.2G /appsmith-stacks/data/mongodb/collection-10--5793211097493342907.wt 349M /opt/appsmith/backend/plugins/awsLambdaPlugin-v1.34.jar 143M /usr/bin/mongosh 124M /opt/java/lib/modules 110M /usr/lib/mongosh_crypt_v1.so 106M /usr/bin/mongod 106M /opt/appsmith/backend/server.jar 100M /appsmith-stacks/data/mongodb/journal/WiredTigerPreplog.0000000002 100M /appsmith-stacks/data/mongodb/journal/WiredTigerPreplog.0000000001 100M /appsmith-stacks/data/mongodb/journal/WiredTigerLog.0000000022 94M /opt/node/bin/node 75M /usr/bin/mongos 71M /usr/lib/x86_64-linux-gnu/libLLVM-10.so.1 68M /opt/temporal/cli/bin/temporal 62M /opt/temporal/temporal-server 58M /usr/bin/mongo 50M /opt/appsmith/rts/node_modules/@swc/core-linux-x64-gnu/swc.linux-x64-gnu.node 49M /opt/java/lib/src.zip 47M /opt/appsmith/backend/plugins/firestorePlugin-v1.34.jar 39M /opt/caddy/caddy_vanilla 39M /opt/caddy/caddy 37M /opt/newrelic/newrelic.jar 36M /opt/keycloak/lib/lib/main/org.keycloak.keycloak-themes-24.0.0.jar 35M /root/.npm/_cacache/content-v2/sha512/4c/95/7c4e1f21d29bfa830c04a9c4d421b39956a7ca8ffeaa5a03419d9b878b705877558acef5c61a0d2bd60a2bc257daa5a0b7326b3f46a79df5796797dc630d 34M /opt/temporal/temporal-sql-tool 34M /opt/appsmith/backend/plugins/snowflakePlugin-v1.34.jar 33M /opt/appsmith/backend/plugins/databricksPlugin-v1.34.jar 27M /usr/lib/x86_64-linux-gnu/libicudata.so.66.1 26M /opt/appsmith/editor/static/js/main.2d1c90a3.js.map 23M /opt/java/lib/server/libjvm.so 22M /opt/java/jmods/java.base.jmod 20M /opt/appsmith/rts/node_modules/@temporalio/core-bridge/releases/x86_64-unknown-linux-gnu/index.node 20M /opt/appsmith/rts/node_modules/@temporalio/core-bridge/releases/aarch64-unknown-linux-gnu/index.node 18M /opt/appsmith/rts/node_modules/@temporalio/core-bridge/releases/x86_64-pc-windows-msvc/index.node 18M /opt/appsmith/rts/node_modules/@temporalio/core-bridge/releases/x86_64-apple-darwin/index.node 17M /root/.npm/_cacache/content-v2/sha512/99/25/5557f3c5cc21ad2359d5410cb1df837008c812bab17a657fe67bca54017d39e2fb04fe94852faeb137e91039eff567f2ce7785265c5919fc4cce4a761c4a 17M /opt/appsmith/rts/node_modules/@temporalio/core-bridge/releases/aarch64-apple-darwin/index.node 16M /var/lib/postgresql/14/main/pg_wal/000000010000000000000001 16M /appsmith-stacks/data/postgres/main/pg_wal/000000010000000000000005 16M /appsmith-stacks/data/postgres/main/pg_wal/000000010000000000000004 15M /opt/appsmith/editor/static/js/8870.2be82e14.chunk.js.map 14M /usr/bin/mongostat 14M /usr/bin/mongorestore 14M /usr/bin/mongoimport 14M /usr/bin/mongofiles 14M /usr/bin/mongoexport 14M /usr/bin/mongodump 14M /opt/java/jmods/java.desktop.jmod 13M /usr/bin/mongotop 13M /root/.npm/_cacache/content-v2/sha512/98/c5/0ea4b155392921ec1de0401f5bdc6818371e1558f400388cbb24d566d83f5dbef62f9d07bd6c72d8166d7fa1bd37da4e727d268bde43de4e4bec1eddb14b 13M /opt/java/lib/server/classes.jsa 12M /opt/keycloak/lib/lib/main/org.hibernate.orm.hibernate-core-6.4.4.Final.jar 12M /opt/java/lib/server/classes_nocoops.jsa 12M /opt/appsmith/rts/bundle/server.js.map 12M /opt/appsmith/backend/plugins/appsmithAiPlugin-v1.34.jar 11M /opt/appsmith/editor/Github_add_deploykey.gif 11M /appsmith-stacks/logs/editor/error-5f7b2ebd5c26.log.2 11M /appsmith-stacks/logs/editor/error-5f7b2ebd5c26.log.1 11M /appsmith-stacks/logs/editor/access-5f7b2ebd5c26.log.2 11M /appsmith-stacks/logs/editor/access-5f7b2ebd5c26.log.1 11M /appsmith-stacks/logs/backend/backend-5f7b2ebd5c26.log.1 10M /appsmith-stacks/data/mongodb/diagnostic.data/metrics.2024-08-10T22-43-00Z-00000 10M /appsmith-stacks/data/mongodb/diagnostic.data/metrics.2024-08-09T21-42-56Z-00000 10M /appsmith-stacks/data/mongodb/diagnostic.data/metrics.2024-08-08T20-07-56Z-00000 10M /appsmith-stacks/data/mongodb/diagnostic.data/metrics.2024-08-07T18-32-55Z-00000 10M /appsmith-stacks/data/mongodb/diagnostic.data/metrics.2024-08-06T17-02-54Z-00000

naptha77 commented 3 months ago

I created a brand new appsmith container and imported the app from my same git repo. It was still very slow but worked that time. My mongodb file is only 3.9MB in the new container: 3.9M /appsmith-stacks/data/mongodb/collection-10--7097894050882452922.wt

My app displays lots of images, so mongo may be caching them, slowing down the git operations over time. Although I expect it'd be ignoring *.wt files so it shouldn't affect git.

The root issue still persists however which is very slow git operations. I assume it'll eventually timeout on this container as well.

What range of speeds should I be expecting for git operations?

Should I try using an external mongodb instance so I don't have that 1.2GB database sitting inside my container?

New git operation logs showing new speeds:

[2024-08-13 22:07:41,472] ... - Going to get branch list for application 66bbd7f044507f7b3f6a5de5 [2024-08-13 22:07:41,492] ... - Git command listBranch is trying to acquire the lock for application id 66bbd7f044507f7b3f6a5de5 [2024-08-13 22:07:41,631] ... - boundedElastic-23: Get branches for the application 66bbd7bb44507f7b3f6a5dd9/66bbd7f044507f7b3f6a5de5/amazon-appsmith [2024-08-13 22:07:42,722] ... - Git command autoCommitEligibility is trying to acquire the lock for application id 66bbd7f044507f7b3f6a5de5 [2024-08-13 22:07:52,811] ... - Execute time: JGIT git_reset, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 9980ms [2024-08-13 22:07:52,839] ... - boundedElastic-19: Switching to the branch main [2024-08-13 22:08:00,044] ... - Execute time: JGIT git_reset, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 7193ms [2024-08-13 22:08:00,066] ... - page dsl retrieved from file system [2024-08-13 22:08:00,085] ... - server schema for application id : 66bbd7f044507f7b3f6a5de5 and branch name : main is : 8 [2024-08-13 22:08:00,087] ... - application with id: 66bbd7f044507f7b3f6a5de5, and branch name: main is not eligible for autocommit [2024-08-13 22:08:00,137] ... - Going to get status for default application 66bbd7f044507f7b3f6a5de5, branch main [2024-08-13 22:08:00,277] ... - Git command status is trying to acquire the lock for application id 66bbd7f044507f7b3f6a5de5 [2024-08-13 22:08:04,093] ... - Execute time: JGIT git_fetch, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 3784ms [2024-08-13 22:08:08,926] ... - Execute time: JGIT git_reset, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 8571ms [2024-08-13 22:08:08,954] ... - boundedElastic-20: Switching to the branch main [2024-08-13 22:08:17,552] ... - Execute time: JGIT git_reset, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 8584ms [2024-08-13 22:08:32,304] ... - Execute time: FS application save, Time elapsed: 31995ms [2024-08-13 22:08:32,410] ... - boundedElastic-20: Get status for repo /appsmith-stacks/git-storage/66bbd7bb44507f7b3f6a5dd9/66bbd7f044507f7b3f6a5de5/amazon-appsmith, branch main [2024-08-13 22:08:40,419] ... - Execute time: JGIT git_status, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 8114ms [2024-08-13 22:08:56,475] ... - Execute time: JGIT git_reset, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 15962ms [2024-08-13 22:08:56,502] ... - boundedElastic-20: Switching to the branch main [2024-08-13 22:09:11,852] ... - Execute time: JGIT git_reset, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 15337ms [2024-08-13 22:09:32,320] ... - update layout received for page 66bbd82544507f7b3f6a5dff [2024-08-13 22:09:33,798] ... - Going to get status for default application 66bbd7f044507f7b3f6a5de5, branch main [2024-08-13 22:09:33,925] ... - Git command status is trying to acquire the lock for application id 66bbd7f044507f7b3f6a5de5 [2024-08-13 22:09:37,564] ... - Execute time: JGIT git_fetch, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 3626ms [2024-08-13 22:09:50,604] ... - Execute time: JGIT git_reset, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 16623ms [2024-08-13 22:09:50,634] ... - boundedElastic-21: Switching to the branch main [2024-08-13 22:10:06,085] ... - Execute time: JGIT git_reset, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 15438ms [2024-08-13 22:10:20,593] ... - Execute time: FS application save, Time elapsed: 46655ms [2024-08-13 22:10:20,700] ... - boundedElastic-21: Get status for repo /appsmith-stacks/git-storage/66bbd7bb44507f7b3f6a5dd9/66bbd7f044507f7b3f6a5de5/amazon-appsmith, branch main [2024-08-13 22:10:44,454] ... - Execute time: JGIT git_reset, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 15547ms [2024-08-13 22:10:44,456] ... - Execute time: JGIT git_status, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 23862ms [2024-08-13 22:11:00,021] ... - Execute time: JGIT git_reset, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 15460ms [2024-08-13 22:11:00,050] ... - boundedElastic-18: Switching to the branch main [2024-08-13 22:11:15,599] ... - Execute time: JGIT git_reset, appId 66bbd7f044507f7b3f6a5de5, Time elapsed: 15531ms

nidhi-nair commented 3 months ago

I should have mentioned the steps more clearly in my previous comment. I meant to check the size of the repo itself, which is 1.65MB as you mentioned. That's not too high for us to see this kind of latency. The rest of the data should not matter, those are to do with the DB, logs, and other artefacts for Appsmith.

Next we can attempt to set up some observability on your system to check what step exactly is failing here. I'm just heading out for a small vacation, but would you be available for a call early next week and may be we attempt to resolve this in sync, @naptha77 ?

naptha77 commented 3 months ago

Thanks @nidhi-nair, sounds great.

The operation that is timing out is http://localhost/api/v1/git/status/app/66___37?compareRemote=true. It fails after exactly 2 minutes.

Is there any config where I can increase that timeout? At least then I can keep working in the meantime.

I've tried creating a new container on a new VM, importing my app then pointing it at a new bitbucket repo (as opposed to github). I still have thew same issue - the compareRemote call above takes 1.9 minutes so almost times out.

So I assume it's something related to my appsmith app itself.

I imported a very early version of my app into a new repo and the compareRemote took 28 seconds. But the repo is only 100k, so only 15% of the size of the new one.

Anyway, looking forward to chatting next week

rmmlopes commented 3 months ago

Just wanted to say that I'm seeing the same types of delays with git operations. This has been happening from the start.

It is so bad that I'm hesitant to recommend Appsmith to other developers due to this performance issue.

Self hosted on Azure Container with the repo in Azure Dev Ops.

infinitetrooper commented 3 months ago

@rmmlopes - Apologies for the current experience, we're aware of the poor performance, especially with Azure File System. We're working on a large project to drastically improve this, I'll share a GitHub ticket once we're closer to development.

nidhi-nair commented 3 months ago

@naptha77 here's my Calendly link, please feel free to pick a slot that works for you and we'll figure out how to bring in some more visibility for you. Also, before we get into the call, please make sure to acquire access to all the components of Appsmith so the debugging proceeds seamlessly.

@rmmlopes sorry that you're facing this as well. Azure FS like Akhil mentioned seems to have latency problems of its own that renders it impossible for use. I'd love to chat if you're up for it though, it would be interesting to see if there's any peculiarities in your system different from the ones we're already keeping track of.

rmmlopes commented 2 months ago

@rmmlopes sorry that you're facing this as well. Azure FS like Akhil mentioned seems to have latency problems of its own that renders it impossible for use. I'd love to chat if you're up for it though, it would be interesting to see if there's any peculiarities in your system different from the ones we're already keeping track of.

I am also starting to see a lot of errors on the UI when editing JS code in the appsmith UI saying something to the effect that "X function already exists" when I'm editing that piece of code. At this point I have come to the conclusion that Appsmith should not be run in Azure. I think you should update your web documentation to this effect so that people don't waste a bunch of time trying to get it to work.

naptha77 commented 2 months ago

I decided to remove the git integration and just export the project JSON after each change, checking it into my own github repo. It means deployments are instant and always work. I may revisit later if bugs are fixed as above, but at the moment it's not worth spending any more time on