Server crashes due to locking problems

[michielbdejong]

The server is crashing repeatedly when I try to log in to view https://michielbdejong.pivot.pondersource.com/README/
Investigating.

[michielbdejong]

2024-11-21T13:59:09.109Z [HandlerServerConfigurator] {Primary} info: Received GET request for /README/
2024-11-21T13:59:09.131Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/.acl
2024-11-21T13:59:09.148Z [PermissionBasedAuthorizer] {Primary} warn: Unauthenticated agent has no read permissions
2024-11-21T13:59:09.282Z [HandlerServerConfigurator] {Primary} info: Received GET request for /mash.css.map
2024-11-21T13:59:09.297Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/.acl
2024-11-21T13:59:09.319Z [PermissionBasedAuthorizer] {Primary} warn: Unauthenticated agent has no read permissions
2024-11-21T13:59:09.469Z [HandlerServerConfigurator] {Primary} info: Received GET request for /.well-known/openid-configuration
2024-11-21T13:59:10.015Z [HandlerServerConfigurator] {Primary} info: Received GET request for /.well-known/openid-configuration
2024-11-21T13:59:10.272Z [HandlerServerConfigurator] {Primary} info: Received GET request for /.oidc/auth?client_id=iv8eipbxcqAu3HIEEn0Kx&redirect_uri=https%3A%2F%2Fmichielbdejong.pivot.pondersource.com%2FREADME%2F&response_type=code&scope=openid%20offline_access%20webid&state=920524e133f5481bb1f5e79160fd773f&code_challenge=fkUjOoIOhWqkw2f7k5h-4ZoULxXGkic0vv-iVXan_14&code_challenge_method=S256&prompt=none&response_mode=query
2024-11-21T13:59:10.768Z [HandlerServerConfigurator] {Primary} info: Received GET request for /README/?code=_FN9dxgjuOKQjruxq2dG3XFj0kELdtXd2FrtxOSjRyr&state=920524e133f5481bb1f5e79160fd773f&iss=https%3A%2F%2Fpivot.pondersource.com%2F
2024-11-21T13:59:10.777Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/.acl
2024-11-21T13:59:10.797Z [PermissionBasedAuthorizer] {Primary} warn: Unauthenticated agent has no read permissions
2024-11-21T13:59:10.914Z [HandlerServerConfigurator] {Primary} info: Received GET request for /mash.css.map
2024-11-21T13:59:10.922Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/.acl
2024-11-21T13:59:10.933Z [PermissionBasedAuthorizer] {Primary} warn: Unauthenticated agent has no read permissions
2024-11-21T13:59:10.938Z [HandlerServerConfigurator] {Primary} info: Received GET request for /.well-known/openid-configuration
2024-11-21T13:59:11.039Z [HandlerServerConfigurator] {Primary} info: Received OPTIONS request for /.oidc/token
2024-11-21T13:59:11.130Z [HandlerServerConfigurator] {Primary} info: Received POST request for /.oidc/token
2024-11-21T13:59:11.334Z [HandlerServerConfigurator] {Primary} info: Received GET request for /.oidc/jwks
2024-11-21T13:59:11.439Z [HandlerServerConfigurator] {Primary} info: Received GET request for /README/
2024-11-21T13:59:11.455Z [HandlerServerConfigurator] {Primary} info: Received GET request for /profile/card
2024-11-21T13:59:11.473Z [HandlerServerConfigurator] {Primary} info: Received GET request for /profile/card
2024-11-21T13:59:11.488Z [HandlerServerConfigurator] {Primary} info: Received GET request for /profile/card
2024-11-21T13:59:11.499Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/profile/card.acl
2024-11-21T13:59:11.510Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/profile/card.acl
2024-11-21T13:59:11.773Z [HandlerServerConfigurator] {Primary} info: Received GET request for /.well-known/openid-configuration
2024-11-21T13:59:11.787Z [HandlerServerConfigurator] {Primary} info: Received GET request for /.well-known/openid-configuration
2024-11-21T13:59:11.790Z [HandlerServerConfigurator] {Primary} info: Received GET request for /.oidc/jwks
2024-11-21T13:59:11.798Z [HandlerServerConfigurator] {Primary} info: Received GET request for /.oidc/jwks
2024-11-21T13:59:11.806Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: https://michielbdejong.pivot.pondersource.com/profile/card#me, client ID: iv8eipbxcqAu3HIEEn0Kx, issuer: https://pivot.pondersource.com/
2024-11-21T13:59:11.810Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: https://michielbdejong.pivot.pondersource.com/profile/card#me, client ID: iv8eipbxcqAu3HIEEn0Kx, issuer: https://pivot.pondersource.com/
2024-11-21T13:59:11.815Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/profile/card.acl
2024-11-21T13:59:11.817Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/.acl
2024-11-21T13:59:11.857Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/profile/card.acl
2024-11-21T13:59:11.939Z [HandlerServerConfigurator] {Primary} info: Received GET request for /README
2024-11-21T13:59:11.947Z [DPoPWebIdExtractor] {Primary} warn: Error verifying WebID via DPoP-bound access token: The DPoP proof htu parameter must be the HTTP request URI without query and fragment parts.
Actual: https://michielbdejong.pivot.pondersource.com/README
Expected: https://michielbdejong.pivot.pondersource.com/README/
2024-11-21T13:59:11.952Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/README.acl
2024-11-21T13:59:11.981Z [HandlerServerConfigurator] {Primary} info: Received GET request for /README/
2024-11-21T13:59:12.014Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: https://michielbdejong.pivot.pondersource.com/profile/card#me, client ID: iv8eipbxcqAu3HIEEn0Kx, issuer: https://pivot.pondersource.com/
2024-11-21T13:59:12.030Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/.acl
2024-11-21T13:59:12.077Z [HandlerServerConfigurator] {Primary} info: Received GET request for /
2024-11-21T13:59:12.084Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: https://michielbdejong.pivot.pondersource.com/profile/card#me, client ID: iv8eipbxcqAu3HIEEn0Kx, issuer: https://pivot.pondersource.com/
2024-11-21T13:59:12.088Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/.acl
2024-11-21T13:59:12.117Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/.acl
2024-11-21T13:59:12.156Z [HandlerServerConfigurator] {Primary} info: Received GET request for /settings/prefs.ttl
2024-11-21T13:59:12.161Z [HandlerServerConfigurator] {Primary} info: Received GET request for /README.meta
2024-11-21T13:59:12.166Z [HandlerServerConfigurator] {Primary} info: Received GET request for /README/
2024-11-21T13:59:12.175Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: https://michielbdejong.pivot.pondersource.com/profile/card#me, client ID: iv8eipbxcqAu3HIEEn0Kx, issuer: https://pivot.pondersource.com/
2024-11-21T13:59:12.185Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: https://michielbdejong.pivot.pondersource.com/profile/card#me, client ID: iv8eipbxcqAu3HIEEn0Kx, issuer: https://pivot.pondersource.com/
2024-11-21T13:59:12.188Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: https://michielbdejong.pivot.pondersource.com/profile/card#me, client ID: iv8eipbxcqAu3HIEEn0Kx, issuer: https://pivot.pondersource.com/
2024-11-21T13:59:12.200Z [PermissionBasedAuthorizer] {Primary} warn: Agent {"agent":{"webId":"https://michielbdejong.pivot.pondersource.com/profile/card#me"},"issuer":{"url":"https://pivot.pondersource.com/"},"client":{"clientId":"iv8eipbxcqAu3HIEEn0Kx"}} has no read permissions
2024-11-21T13:59:12.222Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/settings/.acl
2024-11-21T13:59:12.223Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/.acl
2024-11-21T13:59:12.260Z [HandlerServerConfigurator] {Primary} info: Received GET request for /README
2024-11-21T13:59:12.280Z [DPoPWebIdExtractor] {Primary} warn: Error verifying WebID via DPoP-bound access token: The DPoP proof htu parameter must be the HTTP request URI without query and fragment parts.
Actual: https://michielbdejong.pivot.pondersource.com/README
Expected: https://michielbdejong.pivot.pondersource.com/README/
2024-11-21T13:59:12.298Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/settings/.acl
2024-11-21T13:59:12.405Z [HandlerServerConfigurator] {Primary} info: Received GET request for /settings/publicTypeIndex.ttl
2024-11-21T13:59:12.410Z [HandlerServerConfigurator] {Primary} info: Received GET request for /settings/privateTypeIndex.ttl
2024-11-21T13:59:12.420Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: https://michielbdejong.pivot.pondersource.com/profile/card#me, client ID: iv8eipbxcqAu3HIEEn0Kx, issuer: https://pivot.pondersource.com/
2024-11-21T13:59:12.422Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: https://michielbdejong.pivot.pondersource.com/profile/card#me, client ID: iv8eipbxcqAu3HIEEn0Kx, issuer: https://pivot.pondersource.com/
2024-11-21T13:59:12.428Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/settings/publicTypeIndex.ttl.acl
2024-11-21T13:59:12.431Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/settings/.acl
2024-11-21T13:59:12.496Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/settings/publicTypeIndex.ttl.acl
2024-11-21T13:59:12.510Z [WebAclReader] {Primary} info: Found applicable ACL document https://michielbdejong.pivot.pondersource.com/settings/.acl
Process is halting due to an uncaughtException with error Cannot read properties of undefined (reading 'updateTimeout')
/root/pivot/node_modules/proper-lockfile/lib/lockfile.js:104
    if (lock.updateTimeout) {
             ^

TypeError: Cannot read properties of undefined (reading 'updateTimeout')
    at updateLock (/root/pivot/node_modules/proper-lockfile/lib/lockfile.js:104:14)
    at /root/pivot/node_modules/proper-lockfile/lib/lockfile.js:167:17
    at FSReqCallback.oncomplete (node:fs:187:23)

Node.js v20.18.0

[michielbdejong]

The server should of course never crash, but it seems related to this:

The DPoP proof htu parameter must be the HTTP request URI without query and fragment parts.
Actual: https://michielbdejong.pivot.pondersource.com/README
Expected: https://michielbdejong.pivot.pondersource.com/README/

And maybe the locking mechanism gets confused due to the with/without trailing slash confusion. It's probably better to find a different point in the architecture to address #4, and then fix it once and for all for both publish and non-public resources, and without confusing the DPoP checker and the locking mechanism.