Azure AD SAML SSO and Grist

Ask for Help
1

I’m trying to configure my self-hosted instance with Azure AD via SAML and I’m wondering if anyone has gotten this setup to work.

I’m using a similar configuration to the one suggested in the comments at the top of grist-core/app/server/lib/SamlConfig.ts at main · gristlabs/grist-core · GitHub to no good. I get successfully redirected to Azure AD’s login screen, but after entering my credentials, I get the following error:

AADSTS700016: Application with identifier ‘http://localhost:8484/saml/metadata.xml’ was not found in the directory ‘My Company’. This can happen if the application has not been installed by the administrator of the tenant or consented to by any user in the tenant. You may have sent your authentication request to the wrong tenant.

I’m testing at localhost and it seems that, somewhere along the way, the metadata URL was used as the Azure AD’s application ID (usually an UUID4 id). What am I missing? Any help would be greatly appreciated. Thanks!

2

Hi @Ivan_Filgueiras, I do see an entity_id being set to the metadata URL here:

In Azure, where you are configuring SAML settings, do you see any possibility to edit an Entity ID, perhaps in a section called Service Provider Settings?

3

I’ve managed to make it work by setting my Entity ID on Azure AD to the URL that Grist’s SSO code ends up making (in this case, http://localhost:8484/saml/metadata.xml). It’s a weird workaround, but it worked just fine as far as I can tell.

There are some weird error messages in the logs, so maybe there is something broken that I’m not bumping into yet. What do you think @paul-grist? Errors below:

2022-08-03 01:49:44.632 - error: ScopedSession[g-bKkbidTg2p9mSm9QU2jXKe]: Error updating sessionStore: TypeError: Cannot read property ‘maxAge’ of undefined
…
2022-08-03 01:49:47.834 - error: ScopedSession[g-4S1y9BqjhqmeDYG2QaWvgb]: Error updating sessionStore: Error: failed to load session

4

Glad things are improved! Hmm I believe the first error you quote can be tickled by hitting a /logout endpoint without actually having a session in place. But the second error makes me think there might be more going on. Do you see an actual problem in behavior? It would be good to check this with any grist cookies lying around from previous trials deleted.

5

I’ve jus re-run a new session with all cookies cleared and I’ve exported the logs with DEBUG=1. Find it below.

Everything worked fine, even logging out. But I guess I should try to fix the code to work properly with Azure AD regardless :slight_smile:

Welcome to Grist.
2022-08-04 12:13:39.024 - e[32minfoe[39m: == Grist version is 0.1.1 (commit unknown)
2022-08-04 12:13:39.031 - e[32minfoe[39m: Loading empty config because /persist/config.json missing
2022-08-04 12:13:39.038 - e[32minfoe[39m: SamlConfig set with host http://localhost:8484, IdP https://login.microsoftonline.com/<my-tenant-uuid>/saml2
2022-08-04 12:13:39.053 - e[33mwarne[39m: did not find an appropriately named example workspace in deployment
2022-08-04 12:13:39.070 - e[32minfoe[39m: No plugins directory: ENOENT: no such file or directory, scandir '/grist/.grist/plugins'
2022-08-04 12:13:39.078 - e[32minfoe[39m: Found 1 valid plugins on the system
2022-08-04 12:13:39.078 - e[34mdebuge[39m: PLUGIN builtIn/core -- /grist/plugins/core
2022-08-04 12:13:39.088 - e[32minfoe[39m: Server timeouts: keepAliveTimeout 305000 headersTimeout 306000
2022-08-04 12:13:39.094 - e[32minfoe[39m: server(home,docs,static) available at 0.0.0.0:8484
2022-08-04 12:13:39.104 - e[33mwarne[39m: Failed to create GoogleAuth endpoint: GOOGLE_CLIENT_SECRET is not defined
2022-08-04 12:13:39.110 - e[32minfoe[39m: == appRoot: /grist
2022-08-04 12:13:39.110 - e[32minfoe[39m: == docsRoot: /persist/docs
2022-08-04 12:13:39.110 - e[32minfoe[39m: == defaultBaseDomain: undefined
2022-08-04 12:13:39.110 - e[32minfoe[39m: == pluginUrl: undefined
2022-08-04 12:13:39.110 - e[32minfoe[39m: == instanceRoot: /persist
2022-08-04 12:13:39.110 - e[32minfoe[39m: == tag: unknown
2022-08-04 12:13:39.110 - e[32minfoe[39m: == database: sqlite:///persist/home.sqlite3
2022-08-04 12:13:39.111 - e[32minfoe[39m: == userRoot: /grist/.grist
2022-08-04 12:13:39.111 - e[32minfoe[39m: == loginMiddlewareComment: saml
2022-08-04 12:13:39.111 - e[32minfoe[39m: == docWorkerId: testDocWorkerId_8484
2022-08-04 12:13:39.111 - e[32minfoe[39m: == grist.login.skipSession: - [GRIST_IGNORE_SESSION]
2022-08-04 12:13:39.112 - e[32minfoe[39m: == grist.login.forced: - [GRIST_FORCE_LOGIN]
2022-08-04 12:13:39.112 - e[32minfoe[39m: == grist.externalStorage.disable: - [GRIST_DISABLE_S3]
2022-08-04 12:13:39.112 - e[32minfoe[39m: == grist.externalStorage.active: false
2022-08-04 12:13:39.119 - e[32minfoe[39m: activity docCount=0, orgCount=1, orgInGoodStandingCount=1, userCount=5, userWithLoginCount=5
2022-08-04 12:13:44.192 - e[34mdebuge[39m: Auth[GET]: localhost:8484 / customHostSession=, method=GET, host=localhost:8484, path=/, org=example, email=anon@getgrist.com, userId=1, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:44.203 - e[34mdebuge[39m: Authorizer: redirecting to sign up
2022-08-04 12:13:44.253 localhost:8484 GET / 302 49.686 ms - 2398
2022-08-04 12:13:49.387 - e[32minfoe[39m: SamlConfig: got SAML response for ireche@example.com (Ivan Ferrucio Reche da Silva Filgueiras) redirecting to http://localhost:8484/
2022-08-04 12:13:49.430 - e[31merrore[39m: ScopedSession[g-a8KqT3kkEKhXwotn2DbESs]: Error updating sessionStore: Error: failed to load session
2022-08-04 12:13:49.433 localhost:8484 POST /saml/assert 302 152.439 ms - 88
2022-08-04 12:13:49.455 - e[34mdebuge[39m: Auth[GET]: localhost:8484 / customHostSession=, method=GET, host=localhost:8484, path=/, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:49.456 - e[34mdebuge[39m: welcoming user: ireche@example.com
2022-08-04 12:13:49.549 localhost:8484 GET / 200 83.658 ms - 3676
2022-08-04 12:13:49.596 localhost:8484 GET /v/unknown/jqueryui/themes/smoothness/jquery-ui.css 304 7.409 ms - -
2022-08-04 12:13:49.608 localhost:8484 GET /v/unknown/bundle.css 304 3.796 ms - -
2022-08-04 12:13:49.613 localhost:8484 GET /v/unknown/bootstrap/dist/css/bootstrap.min.css 304 5.971 ms - -
2022-08-04 12:13:49.614 localhost:8484 GET /v/unknown/hljs.default.css 304 3.294 ms - -
2022-08-04 12:13:49.626 localhost:8484 GET /v/unknown/bootstrap-datepicker/dist/css/bootstrap-datepicker3.min.css 304 6.803 ms - -
2022-08-04 12:13:49.628 localhost:8484 GET /v/unknown/icons/icons.css 304 4.581 ms - -
2022-08-04 12:13:49.629 localhost:8484 GET /v/unknown/jqueryui/jquery-ui.min.js 304 8.594 ms - -
2022-08-04 12:13:49.633 localhost:8484 GET /v/unknown/bootstrap/dist/js/bootstrap.min.js 304 10.685 ms - -
2022-08-04 12:13:49.635 localhost:8484 GET /v/unknown/bootstrap-datepicker/dist/js/bootstrap-datepicker.min.js 304 12.380 ms - -
2022-08-04 12:13:49.638 localhost:8484 GET /v/unknown/jquery/dist/jquery.min.js 304 14.158 ms - -
2022-08-04 12:13:49.640 localhost:8484 GET /v/unknown/main.bundle.js 304 2.773 ms - -
2022-08-04 12:13:49.642 localhost:8484 GET /v/unknown/browser-check.js 304 0.852 ms - -
2022-08-04 12:13:49.652 localhost:8484 GET /v/unknown/img/gplaypattern.png 304 0.660 ms - -
2022-08-04 12:13:49.950 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /session/access/all customHostSession=, method=GET, host=localhost:8484, path=/session/access/all, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:49.993 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /session/access/active customHostSession=, method=GET, host=localhost:8484, path=/session/access/active, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:50.037 localhost:8484 GET /o/example/api/session/access/all 200 52.096 ms - 734
2022-08-04 12:13:50.058 localhost:8484 GET /o/example/api/session/access/active 200 77.245 ms - 582
2022-08-04 12:13:50.101 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /orgs/3/workspaces customHostSession=, method=GET, host=localhost:8484, path=/orgs/3/workspaces, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:50.143 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /orgs/3/usage customHostSession=, method=GET, host=localhost:8484, path=/orgs/3/usage, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:50.161 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /templates customHostSession=, method=GET, host=localhost:8484, path=/templates, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:50.187 localhost:8484 GET /o/example/api/orgs/3/workspaces?includeSupport=1 200 48.552 ms - 195
2022-08-04 12:13:50.207 localhost:8484 GET /o/example/api/orgs/3/usage 304 67.946 ms - -
2022-08-04 12:13:50.229 localhost:8484 GET /o/example/api/templates?onlyFeatured=1 404 101.385 ms - 34
2022-08-04 12:13:54.577 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /orgs/3/workspaces customHostSession=, method=GET, host=localhost:8484, path=/orgs/3/workspaces, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:54.657 localhost:8484 GET /o/example/api/orgs/3/workspaces?includeSupport=1 304 38.297 ms - -
2022-08-04 12:13:57.682 - e[34mdebuge[39m: Auth[POST]: localhost:8484 /workspaces/3/docs customHostSession=, method=POST, host=localhost:8484, path=/workspaces/3/docs, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:57.804 localhost:8484 POST /o/example/api/workspaces/3/docs 200 101.985 ms - 24
2022-08-04 12:13:57.824 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /orgs/3/workspaces customHostSession=, method=GET, host=localhost:8484, path=/orgs/3/workspaces, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:57.860 localhost:8484 GET /o/example/api/orgs/3/workspaces?includeSupport=1 200 31.976 ms - 389
2022-08-04 12:13:57.875 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /docs/cmPEpwBuq4RWL9jwCuN4tx customHostSession=, method=GET, host=localhost:8484, path=/docs/cmPEpwBuq4RWL9jwCuN4tx, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:57.899 localhost:8484 GET /o/example/api/docs/cmPEpwBuq4RWL9jwCuN4tx 200 16.620 ms - 868
2022-08-04 12:13:57.988 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /cmPEpwBuq4RW/Untitled-document customHostSession=, method=GET, host=localhost:8484, path=/cmPEpwBuq4RW/Untitled-document, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:58.019 localhost:8484 GET /cmPEpwBuq4RW/Untitled-document 200 27.666 ms - 4672
2022-08-04 12:13:58.039 localhost:8484 GET /v/unknown/jqueryui/themes/smoothness/jquery-ui.css 304 1.041 ms - -
2022-08-04 12:13:58.044 localhost:8484 GET /v/unknown/hljs.default.css 304 1.628 ms - -
2022-08-04 12:13:58.046 localhost:8484 GET /v/unknown/bootstrap/dist/css/bootstrap.min.css 304 4.629 ms - -
2022-08-04 12:13:58.046 localhost:8484 GET /v/unknown/bootstrap-datepicker/dist/css/bootstrap-datepicker3.min.css 304 3.606 ms - -
2022-08-04 12:13:58.047 localhost:8484 GET /v/unknown/bundle.css 304 2.371 ms - -
2022-08-04 12:13:58.049 localhost:8484 GET /v/unknown/icons/icons.css 304 3.701 ms - -
2022-08-04 12:13:58.053 localhost:8484 GET /v/unknown/jquery/dist/jquery.min.js 304 4.384 ms - -
2022-08-04 12:13:58.066 localhost:8484 GET /v/unknown/jqueryui/jquery-ui.min.js 304 5.618 ms - -
2022-08-04 12:13:58.067 localhost:8484 GET /v/unknown/bootstrap/dist/js/bootstrap.min.js 304 5.866 ms - -
2022-08-04 12:13:58.068 localhost:8484 GET /v/unknown/main.bundle.js 304 3.677 ms - -
2022-08-04 12:13:58.069 localhost:8484 GET /v/unknown/browser-check.js 304 3.683 ms - -
2022-08-04 12:13:58.069 localhost:8484 GET /v/unknown/bootstrap-datepicker/dist/js/bootstrap-datepicker.min.js 304 7.542 ms - -
2022-08-04 12:13:58.218 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /session/access/all customHostSession=, method=GET, host=localhost:8484, path=/session/access/all, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:58.243 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /session/access/active customHostSession=, method=GET, host=localhost:8484, path=/session/access/active, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:58.260 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /worker/cmPEpwBuq4RWL9jwCuN4tx customHostSession=, method=GET, host=localhost:8484, path=/worker/cmPEpwBuq4RWL9jwCuN4tx, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:58.266 localhost:8484 GET /o/example/api/session/access/all 304 32.643 ms - -
2022-08-04 12:13:58.304 localhost:8484 GET /o/example/api/worker/cmPEpwBuq4RWL9jwCuN4tx 200 31.365 ms - 55
2022-08-04 12:13:58.305 localhost:8484 GET /o/example/api/session/access/active 304 54.241 ms - -
2022-08-04 12:13:58.307 localhost:8484 GET /v/unknown/652.bundle.js 304 0.820 ms - -
2022-08-04 12:13:58.342 localhost:8484 GET /v/unknown/684.bundle.js 304 4.151 ms - -
2022-08-04 12:13:58.344 localhost:8484 GET /v/unknown/119.bundle.js 304 4.118 ms - -
2022-08-04 12:13:58.345 localhost:8484 GET /v/unknown/931.bundle.js 304 4.455 ms - -
2022-08-04 12:13:58.346 localhost:8484 GET /v/unknown/741.bundle.js 304 4.535 ms - -
2022-08-04 12:13:58.361 localhost:8484 GET /v/unknown/420.bundle.js 304 2.788 ms - -
2022-08-04 12:13:58.361 - e[34mdebuge[39m: Auth[GET]: localhost:8484 /docs/cmPEpwBuq4RW customHostSession=, method=GET, host=localhost:8484, path=/docs/cmPEpwBuq4RW, org=example, email=ireche@example.com, userId=5, altSessionId=tbLm3njx6rcoC8g7WdrEQ7
2022-08-04 12:13:58.416 localhost:8484 GET /o/example/api/docs/cmPEpwBuq4RW 200 46.540 ms - 868
2022-08-04 12:13:58.429 - e[32minfoe[39m: Comm: Got Websocket connection clientId=7878f899a0381381, counter=null, urlPath=/?clientId=0&counter=1&newClient=1&browserSettings=%7B%22timezone%22%3A%22America%2FSao_Paulo%22%7D&user=ireche%40example.com, reuseClient=false
2022-08-04 12:13:58.432 - e[34mdebuge[39m: Client sending clientConnect newClient=true, needReload=false, docsClosed=0, missedMessages=undefined, email=ireche@example.com, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1
2022-08-04 12:13:58.446 - e[32minfoe[39m: Client onMessage '{"reqId":0,"method":"openDoc","args":["cmPEpwBuq4RWL9jwCuN4tx","default",null]}' email=ireche@example.com, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1
2022-08-04 12:13:58.452 - e[34mdebuge[39m: DocManager.openDoc Authorizer key { urlId: 'cmPEpwBuq4RWL9jwCuN4tx', userId: 5, org: 'example' }
2022-08-04 12:13:58.453 - e[34mdebuge[39m: DocManager.fetchDoc cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.482 - e[34mdebuge[39m: ActiveDoc loadDoc access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.486 - e[34mdebuge[39m: ActiveDoc createDoc access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.513 - e[34mdebuge[39m: DB cmPEpwBuq4RWL9jwCuN4tx open successfully
2022-08-04 12:13:58.527 - e[34mdebuge[39m: ActiveDoc Loading 21 normal tables, skipping 0 on-demand tables access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.528 - e[34mdebuge[39m: ActiveDoc Normal tables: Table1, _grist_ACLMemberships, _grist_ACLPrincipals, _grist_ACLResources, _grist_ACLRules, _grist_Attachments, _grist_DocInfo, _grist_External_database, _grist_External_table, _grist_Filters, _grist_Imports, _grist_Pages, _grist_REPL_Hist, _grist_TabBar, _grist_TabItems, _grist_TableViews, _grist_Triggers, _grist_Validations, _grist_Views, _grist_Views_section, _grist_Views_section_field access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.529 - e[34mdebuge[39m: ActiveDoc On-demand tables:  access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.530 - e[34mdebuge[39m: ActiveDoc starting to load 20 tables: _grist_ACLMemberships, _grist_ACLPrincipals, _grist_ACLResources, _grist_ACLRules, _grist_Attachments, _grist_DocInfo, _grist_External_database, _grist_External_table, _grist_Filters, _grist_Imports, _grist_Pages, _grist_REPL_Hist, _grist_TabBar, _grist_TabItems, _grist_TableViews, _grist_Triggers, _grist_Validations, _grist_Views, _grist_Views_section, _grist_Views_section_field access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.573 - e[34mdebuge[39m: 3-pipe Sandbox started sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.591 - e[34mdebuge[39m: DocClients now 1 clients; new client is 7878f899a0381381 (fd 0) access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.592 - e[32minfoe[39m: ActiveDoc will stay open access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.592 - e[32minfoe[39m: ActiveDoc fetchMetaTables access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.601 - e[34mdebuge[39m: Time taken in getRecentMinimalActionGroups: 1 ms
2022-08-04 12:13:58.674 - e[32minfoe[39m: Client onMessage '{"reqId":1,"method":"fetchTable","args":[0,"Table1"]}' email=ireche@example.com, userId=5, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1
2022-08-04 12:13:58.675 - e[34mdebuge[39m: activeDocMethod access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx, docMethod=fetchTable
2022-08-04 12:13:58.677 - e[32minfoe[39m: ActiveDoc fetchQuery {"tableId":"Table1","filters":{}} (regular) access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.680 - e[32minfoe[39m: ActiveDoc fetchQuery -> 0 rows, cols: manualSort, A, B, C access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:58.814 localhost:8484 GET /v/unknown/bootstrap/dist/fonts/glyphicons-halflings-regular.woff2 304 1.827 ms - -
2022-08-04 12:13:59.780 - e[32minfoe[39m: Sandbox stderr: [INFO] [__main__] Ready sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.796 - e[34mdebuge[39m: Sandbox pyCall[load_meta_tables] took 1222 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.797 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.797 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.798 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.798 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.798 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.799 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 2 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.799 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 2 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.799 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.800 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 2 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.800 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.800 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.800 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.800 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 0 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.801 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.801 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.802 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.803 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 2 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.803 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 2 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.803 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 2 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.803 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.804 - e[34mdebuge[39m: ActiveDoc loading 1 tables: Table1 access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.806 - e[34mdebuge[39m: Sandbox pyCall[load_table] took 0 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.807 - e[34mdebuge[39m: Sandbox pyCall[get_table_stats] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.808 - e[32minfoe[39m: Loading complete, table statistics retrieved... access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx, num_user_tables=1, _grist_Tables_rows=1, _grist_Tables_bytes=163, _grist_Tables_column_rows=4, _grist_Tables_column_bytes=640, _grist_ACLMemberships_rows=0, _grist_ACLMemberships_bytes=45, _grist_ACLPrincipals_rows=4, _grist_ACLPrincipals_bytes=270, _grist_ACLResources_rows=1, _grist_ACLResources_bytes=62, _grist_ACLRules_rows=1, _grist_ACLRules_bytes=261, _grist_Attachments_rows=0, _grist_Attachments_bytes=171, _grist_DocInfo_rows=1, _grist_DocInfo_bytes=218, _grist_External_database_rows=0, _grist_External_database_bytes=112, _grist_External_table_rows=0, _grist_External_table_bytes=72, _grist_Filters_rows=0, _grist_Filters_bytes=70, _grist_Imports_rows=0, _grist_Imports_bytes=219, _grist_Pages_rows=1, _grist_Pages_bytes=89, _grist_REPL_Hist_rows=0, _grist_REPL_Hist_bytes=67, _grist_TabBar_rows=1, _grist_TabBar_bytes=62, _grist_TabItems_rows=0, _grist_TabItems_bytes=49, _grist_TableViews_rows=0, _grist_TableViews_bytes=49, _grist_Triggers_rows=0, _grist_Triggers_bytes=92, _grist_Validations_rows=0, _grist_Validations_bytes=63, _grist_Views_rows=1, _grist_Views_bytes=96, _grist_Views_section_rows=2, _grist_Views_section_bytes=516, _grist_Views_section_field_rows=6, _grist_Views_section_field_bytes=452, user_rows=0, user_columns=4, user_bytes=67, user_cells=0, num_on_demand_tables=0
2022-08-04 12:13:59.809 - e[34mdebuge[39m: Sandbox pyCall[initialize] took 1 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.810 - e[34mdebuge[39m: ActiveDoc _applyUserActions(null, [['Calculate']]) access=owners, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.823 - e[34mdebuge[39m: Sandbox pyCall[apply_user_actions] took 12 ms sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.840 - e[34mdebuge[39m: Sandbox memory memory=48984064, sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.841 - e[34mdebuge[39m: Sharing _doApplyUserActions access=owners, docId=cmPEpwBuq4RWL9jwCuN4tx, actionNum=0, linkId=0, otherId=0, numDocActions=0, numRows=0, author=grist
2022-08-04 12:13:59.843 - e[32minfoe[39m: Sandbox row count access=owners, docId=cmPEpwBuq4RWL9jwCuN4tx, rowCount=0
2022-08-04 12:13:59.845 - e[34mdebuge[39m: ActiveDoc _applyUserActions returning {actionNum: 0, retValues: [null], isModification: false} access=owners, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:13:59.846 - e[34mdebuge[39m: ActiveDoc loaded in 1366 ms, InactivityTimer set to 6830 ms access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:14:03.706 - e[32minfoe[39m: Client onMessage '{"reqId":2,"method":"closeDoc","args":[0]}' email=ireche@example.com, userId=5, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1
2022-08-04 12:14:03.707 - e[34mdebuge[39m: activeDocMethod access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx, docMethod=closeDoc
2022-08-04 12:14:03.707 - e[34mdebuge[39m: DocClients removeClient 7878f899a0381381 access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:14:03.708 - e[34mdebuge[39m: DocClients now 0 clients access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:14:03.708 - e[32minfoe[39m: ActiveDoc will self-close in 6830 ms access=owners, userId=5, email=ireche@example.com, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:14:03.719 - e[32minfoe[39m: Client websocket closed; will discard client in 300 sec email=ireche@example.com, userId=5, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1
2022-08-04 12:14:03.821 localhost:8484 GET /logout 302 61.640 ms - 2262
^C2022-08-04 12:14:09.015 - e[32minfoe[39m: Server grist[9] got signal SIGINT; cleaning up (3 handlers)
2022-08-04 12:14:09.017 - e[32minfoe[39m: UploadSet: cleaning up all 0 uploads in set
2022-08-04 12:14:09.019 - e[34mdebuge[39m: Sandbox shutdown starting sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:14:09.022 - e[34mdebuge[39m: ActiveDoc shutdown starting access=owners, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:14:09.030 - e[34mdebuge[39m: DocPluginManager.shutdown cleaning up 1 plugins
2022-08-04 12:14:09.031 - e[34mdebuge[39m: Sandbox shutdown starting sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:14:09.031 - e[34mdebuge[39m: DocPluginManager.shutdown removing tmpDir /tmp/grist-tmp-90ZHcbM2tR3aS
2022-08-04 12:14:09.034 - e[34mdebuge[39m: DocStorage shutdown success
2022-08-04 12:14:09.039 - e[34mdebuge[39m: ActiveDoc shutdown complete access=owners, docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:14:09.066 - e[32minfoe[39m: Client client gone docsClosed=0, email=ireche@example.com, userId=5, age=0, org=example, altSessionId=tbLm3njx6rcoC8g7WdrEQ7, clientId=7878f899a0381381, counter=1
2022-08-04 12:14:09.066 - e[32minfoe[39m: FlexServer shutdown is complete
2022-08-04 12:14:09.148 - e[34mdebuge[39m: Sandbox exited with code 0 signal null sandboxPid=21, flavor=unsandboxed, command=undefined, entryPoint=(default), docId=cmPEpwBuq4RWL9jwCuN4tx
2022-08-04 12:14:09.149 - e[32minfoe[39m: Server grist[9] exiting on SIGINT