Self-hosted with Postgresql + OIDC, delay after every action

I setup a new grist instance with two docker containers (grist + postgresql) and nginx as reverse proxy.

I’m using OIDC with a local gitlab instance.

When i’m accessing grist, i get a delay after pretty much every action. The load on the system isn’t very high. What might cause this delay?

Here are some lines from the docker output. In this example i am entering a text into a spreadsheet cell and pressing enter. There’s always a big delay after the first line (in thie case: “Client onMessage”) before the log messages continue. In this case, 2.7 seconds.

grist     | 2024-08-07 17:42:42.098 - info: Client onMessage '{"reqId":3,"method":"applyUserActions","args":[0,[["AddRecord","Table1",null,{"A... (122 length)' email=sn@x.y, userId=5, age=0, org=myorg, altSessionId=redacted, clientId=redacted2, counter=3                              
grist     | 2024-08-07 17:42:44.828 - debug: activeDocMethod access=owners, userId=5, email=sn@x.y, age=0, org=myorg, altSessionId=redacted, clientId=redacted2, counter=3, docId=redacted3, docMethod=applyUserActions                                                                     
grist     | 2024-08-07 17:42:44.830 - debug: ActiveDoc _applyUserActions(Client redacted2 #3, [['AddRecord', 'Table1', null, {A: 'test1'}]]) access=owners, userId=5, email=sn@x.y, age=0, org=myorg, altSessionId=redacted, clientId=redacted2, counter=3, docId=redacted3                 
grist     | 2024-08-07 17:42:44.835 - debug: Sandbox got call to guessColInfo (3 args) sandboxPid=256, flavor=gvisor, command=undefined, entryPoint=(default), docId=redacted3                                                                                                              
grist     | 2024-08-07 17:42:44.910 - debug: NSandbox pyCall sandboxPid=256, flavor=gvisor, command=undefined, entryPoint=(default), docId=redacted3, funcName=apply_user_actions, loadMs=78                                                                                                
grist     | 2024-08-07 17:42:44.912 - debug: Sandbox memory memory=32116736, sandboxPid=256, flavor=gvisor, command=undefined, entryPoint=(default), docId=redacted3                                                                                                                        
grist     | 2024-08-07 17:42:44.914 - debug: Sharing _doApplyUserActions access=owners, userId=5, email=sn@x.y, age=0, org=myorg, altSessionId=redacted, clientId=redacted2, counter=3, docId=redacted3, actionNum=2, linkId=0, otherId=0, numDocActions=5, numRows=3, author=sn@x.y, session=redacted                                                                                                                                    
grist     | 2024-08-07 17:42:44.917 - debug: _doApplyUserActions (Local): stored #0 [0]: ['ModifyColumn', 'Table1', 'A', {type: 'Text'}]      
grist     | 2024-08-07 17:42:44.918 - debug: _doApplyUserActions (Local): stored #1 [0]: ['UpdateRecord', '_grist_Tables_column', 2, {type: 'Text'}]                                                                                                                                        
grist     | 2024-08-07 17:42:44.919 - debug: _doApplyUserActions (Local): stored #2 [0]: ['ModifyColumn', 'Table1', 'A', {isFormula: false}]  
grist     | 2024-08-07 17:42:44.919 - debug: _doApplyUserActions (Local): stored #3 [0]: ['UpdateRecord', '_grist_Tables_column', 2, {isFormula: false}]                                                                                                                                    
grist     | 2024-08-07 17:42:44.919 - debug: _doApplyUserActions (Local): stored #4 [0]: ['AddRecord', 'Table1', 1, {A: 'test1', manualSort: 1}]                                                                                                                                            
grist     | 2024-08-07 17:42:44.956 - info: Sandbox row count access=owners, userId=5, email=sn@x.y, age=0, org=myorg, altSessionId=redacted, clientId=redacted2, counter=3, docId=redacted3, rowCount=1                                                                                    
grist     | 2024-08-07 17:42:44.960 - debug: ActiveDoc _applyUserActions returning {actionNum: 2, retValues: [1], isModification: true} access=owners, userId=5, email=sn@x.y, age=0, org=myorg, altSessionId=redacted, clientId=redacted2, counter=3, docId=redacted3  

How can i analyze this issue further?

For your setup, the issue may be this one:

2 Likes

Yes, that indeed solved my issue! Thanks.

1 Like