Lock error on uncaught exception

[bourgeoa]

http and mashlib with subdomain

2025-01-19T12:18:01.710Z [MemoryResourceLocker] {Primary} debug: Released lock for http://localhost:8443/.internal/accounts/data/0145e06c-21f9-4edf-9195-242bdcdaa6de. 1 active locks remaining.
Process is halting due to an uncaughtException with error ENOENT: no such file or directory, stat '/mnt/d/github/pivot/data/.internal/locks/633155acad9c251831c4240f44d91c3a'
/mnt/d/github/pivot/node_modules/@solid/community-server/dist/util/locking/FileSystemResourceLocker.js:159
            throw err;
            ^

[Error: ENOENT: no such file or directory, stat '/mnt/d/github/pivot/data/.internal/locks/633155acad9c251831c4240f44d91c3a'] {
  errno: -2,
  code: 'ECOMPROMISED',
  syscall: 'stat',
  path: '/mnt/d/github/pivot/data/.internal/locks/633155acad9c251831c4240f44d91c3a'
}

Node.js v20.18.0

[joachimvh]

Is this a consistent problem and if yes can you give me the steps to reproduce including the configuration? I just tried it myself with a subdomain configuration but did not have any errors.

One thing that is weird from your log is that it contains both a message from the MemoryResourceLocker, and an error thrown from the FileSystemResourceLocker. The first is the locker that is used when you import util/resource-locker/memory.json and the second one is from util/resource-locker/file.json. So the fact that both occur in the same log makes me wonder how they both got instantiated.

[bourgeoa]

The issue happened yesterday once again
I shall try to reproduce it.

• Context CSS 1.7.3 with mashlib on http
• node 20.18 and WSL on W11
• one account/pod created
• mashlib with (I added text/html as disabled)

        "options_disabledMediaRanges": [
          "image/*",
          "application/pdf",
          "text/html"
        ]

• I was trying to resolve/reproduce the Private HTML resources not displaying as expected #41 Dokeli tab recursively loads #43 issues in differents ACL's context
  and I thing the browser URL was test.html document http://bob.localhost:8443/public/test.html
  I was logged in
  and was editing ACL of the same document with the mashlib aclApp (/test.html.acl)

It is a change of authorisation on a loaded document (?? in memory document)

[bourgeoa]

Well just reproduced but this is not what I explained.
Full logs from GET

2025-01-20T11:49:38.441Z [HandlerServerConfigurator] {Primary} info: Received GET request for /public/
2025-01-20T11:49:38.441Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.442Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.442Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.443Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.443Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.443Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.443Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.444Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.444Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.444Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.445Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.445Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.445Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.445Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.446Z [SubdomainIdentifierStrategy] {Primary} debug: Identifier http://bob.localhost:8443/public/ is part of http://localhost:8443/
2025-01-20T11:49:38.446Z [BasicConditionsParser] {Primary} debug: Found the following conditions: {"notMatchesETag":["\"1737373388000-text/turtle\""]}
2025-01-20T11:49:38.446Z [RawBodyParser] {Primary} debug: HTTP request does not have a body, or its empty body is missing a Content-Type header
2025-01-20T11:49:38.447Z [AuthorizingHttpHandler] {Primary} verbose: Extracted credentials: {}
2025-01-20T11:49:38.447Z [AuthorizingHttpHandler] {Primary} verbose: Retrieved required modes: { http://bob.localhost:8443/public/: read }
2025-01-20T11:49:38.448Z [OwnerPermissionReader] {Primary} debug: No authorization resources found that need an ownership check.
2025-01-20T11:49:38.448Z [WebAclReader] {Primary} debug: Retrieving permissions of an unknown agent
2025-01-20T11:49:38.448Z [WebAclReader] {Primary} debug: Searching ACL data for http://bob.localhost:8443/public/
2025-01-20T11:49:38.448Z [WebAclReader] {Primary} debug: Trying to read the direct ACL document of http://bob.localhost:8443/public/
2025-01-20T11:49:38.449Z [WebAclReader] {Primary} debug: Determining existence of  http://bob.localhost:8443/public/.acl
2025-01-20T11:49:38.449Z [MemoryResourceLocker] {Primary} debug: Acquiring lock for http://bob.localhost:8443/public/
2025-01-20T11:49:38.449Z [MemoryResourceLocker] {Primary} debug: Acquired lock for http://bob.localhost:8443/public/. 1 locks active.
2025-01-20T11:49:38.449Z [FileSystemResourceLocker] {Primary} debug: Acquiring lock for http://bob.localhost:8443/public/
Process is halting due to an uncaughtException with error Unable to update lock within the stale threshold
/mnt/d/github/pivot/node_modules/@solid/community-server/dist/util/locking/FileSystemResourceLocker.js:159
            throw err;
            ^

Error: Unable to update lock within the stale threshold
    at /mnt/d/github/pivot/node_modules/proper-lockfile/lib/lockfile.js:136:25
    at callback (/mnt/d/github/pivot/node_modules/graceful-fs/polyfills.js:306:20)
    at FSReqCallback.oncomplete (node:fs:198:5) {
  code: 'ECOMPROMISED'
}

Node.js v20.18.0

[bourgeoa]

Just reproduced again on a pure CSS 1.7.3 not pivot

• logged in
• The issue arise when I put a double // like in http://bob.localhost:3000/public//
  then no issue
• then force reload page (I use chrome Version 131.0.6778.265 (Build officiel) (64 bits))

2025-01-20T14:33:51.915Z [HandlerServerConfigurator] {Primary} info: Received GET request for /public//
2025-01-20T14:33:51.918Z [HandlerServerConfigurator] {Primary} info: Received GET request for /profile/card
2025-01-20T14:33:51.920Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: http://bob.localhost:3000/profile/card#me, client ID: HWPX91MFAlCrwRnkNwA_i, issuer: http://localhost:3000/
2025-01-20T14:33:51.922Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: http://bob.localhost:3000/profile/card#me, client ID: HWPX91MFAlCrwRnkNwA_i, issuer: http://localhost:3000/
2025-01-20T14:33:51.926Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/public//.acl
2025-01-20T14:33:51.927Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/profile/card.acl
2025-01-20T14:33:51.955Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/profile/card.acl
2025-01-20T14:33:51.956Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/public//.acl
2025-01-20T14:33:52.010Z [HandlerServerConfigurator] {Primary} info: Received GET request for /public//.meta
2025-01-20T14:33:52.013Z [HandlerServerConfigurator] {Primary} info: Received GET request for /
2025-01-20T14:33:52.016Z [HandlerServerConfigurator] {Primary} info: Received GET request for /public/
2025-01-20T14:33:52.020Z [HandlerServerConfigurator] {Primary} info: Received GET request for /settings/prefs.ttl
2025-01-20T14:33:52.024Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: http://bob.localhost:3000/profile/card#me, client ID: HWPX91MFAlCrwRnkNwA_i, issuer: http://localhost:3000/
2025-01-20T14:33:52.025Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: http://bob.localhost:3000/profile/card#me, client ID: HWPX91MFAlCrwRnkNwA_i, issuer: http://localhost:3000/
2025-01-20T14:33:52.029Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: http://bob.localhost:3000/profile/card#me, client ID: HWPX91MFAlCrwRnkNwA_i, issuer: http://localhost:3000/
2025-01-20T14:33:52.031Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: http://bob.localhost:3000/profile/card#me, client ID: HWPX91MFAlCrwRnkNwA_i, issuer: http://localhost:3000/
2025-01-20T14:33:52.034Z [PermissionBasedAuthorizer] {Primary} warn: Agent {"agent":{"webId":"http://bob.localhost:3000/profile/card#me"},"issuer":{"url":"http://localhost:3000/"},"client":{"clientId":"HWPX91MFAlCrwRnkNwA_i"}} has no read permissions
2025-01-20T14:33:52.042Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/public//.acl
2025-01-20T14:33:52.043Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/.acl
2025-01-20T14:33:52.047Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/settings/.acl
2025-01-20T14:33:52.079Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/public//.acl
2025-01-20T14:33:52.094Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/settings/.acl
2025-01-20T14:33:52.095Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/.acl
2025-01-20T14:33:52.139Z [HandlerServerConfigurator] {Primary} info: Received GET request for /settings/publicTypeIndex.ttl
2025-01-20T14:33:52.141Z [HandlerServerConfigurator] {Primary} info: Received GET request for /settings/privateTypeIndex.ttl
2025-01-20T14:33:52.144Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: http://bob.localhost:3000/profile/card#me, client ID: HWPX91MFAlCrwRnkNwA_i, issuer: http://localhost:3000/
2025-01-20T14:33:52.145Z [DPoPWebIdExtractor] {Primary} info: Verified WebID via DPoP-bound access token. WebID: http://bob.localhost:3000/profile/card#me, client ID: HWPX91MFAlCrwRnkNwA_i, issuer: http://localhost:3000/
2025-01-20T14:33:52.148Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/settings/publicTypeIndex.ttl.acl
2025-01-20T14:33:52.151Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/settings/.acl
2025-01-20T14:33:52.169Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/settings/publicTypeIndex.ttl.acl
2025-01-20T14:33:52.177Z [WebAclReader] {Primary} info: Found applicable ACL document http://bob.localhost:3000/settings/.acl
Process is halting due to an uncaughtException with error ENOENT: no such file or directory, stat '/mnt/d/github/solidos/workspaces/css-mashlib/data/.internal/locks/cb3138f7691ac12e9038d30cd7ea5658'
/mnt/d/github/solidos/workspaces/css-mashlib/node_modules/@solid/community-server/dist/util/locking/FileSystemResourceLocker.js:159
            throw err;
            ^

[Error: ENOENT: no such file or directory, stat '/mnt/d/github/solidos/workspaces/css-mashlib/data/.internal/locks/cb3138f7691ac12e9038d30cd7ea5658'] {
  errno: -2,
  code: 'ECOMPROMISED',
  syscall: 'stat',
  path: '/mnt/d/github/solidos/workspaces/css-mashlib/data/.internal/locks/cb3138f7691ac12e9038d30cd7ea5658'
}

Node.js v20.18.0

[joachimvh]

I did some tests and can reproduce indeed. Only when combining with mashlib though, not the CSS in itself. But even then this should not cause the server to completely halt so I'll have a look if I can prevent that.

[joachimvh]

The crashing will be fixed by CommunitySolidServer/CommunitySolidServer#1980. Best would be if the error just wouldn't happen but I can't say what the cause is as it currently seems to only happen in combination with mashlib.

[joachimvh]

The server crashing when a lock is compromised has been fixed in v7.1.5. Not sure yet why this error occurs when combining mashlib and CSS with a double slash URL though.