Calendar shared via JMAP Calendar/set with Read Items / read-write is not propagated to the ACL index (SUBSPACE_ACL) — grantee never sees it (PostgreSQL backend)

Issues
1

Issue Description

A calendar shared via JMAP Calendar/set (from the web UI) at Read Items or read-write level is never visible to the grantee in any client. This is distinct from the known “Read Free/Busy is
a scheduling primitive, not a subscription” behaviour — it reproduces with grants that include Read/ReadItems, which per build_access_token should make the calendar visible. The data layer
(archive) and the inverted ACL index (SUBSPACE_ACL) are desynchronized: the archive records the grant, but the ACL index never receives it.

Expected Behavior

After sharing a calendar with mayReadItems (or higher), the grantee should get the owner as a secondary account in their JMAP session and see the calendar in their calendar list.
A row should exist in SUBSPACE_ACL: grant_account_id(grantee) ‖ owner_account_id(owner) ‖ collection=08 (Calendar) ‖ document_id, so that build_access_token → acl_query(AclQuery::HasAccess
{ grant_account_id }) returns the owner.

Actual Behavior

  • Calendar/get on the owner’s calendar correctly returns shareWith with the grantee’s grant (e.g. mayReadItems / mayWriteAll), and the JMAP state id changes on each share change → the
    archive (data layer) is updated.

  • SUBSPACE_ACL contains no row for grant=grantee / owner=owner / collection=08. The grant is never written to the ACL index.

  • Consequently the owner is never added as a secondary account in the grantee’s session, and the calendar never appears in any client (web UI, Bulwark, Thunderbird).

  • A separate, earlier calendar share on the same instance DOES have a correct SUBSPACE_ACL row (value 0x409 = Read|ReadItems|SchedulingReadFreeBusy) and that calendar IS visible — so the ACL
    index write path can work, it just doesn’t for these shares.

  • Toggling the permission (e.g. read → read/write) updates the archive (state id changes) but produces no change in SUBSPACE_ACL, suggesting archive and index stay permanently out of sync
    once diverged.

  • No SQL error in PostgreSQL logs and no WARN/ERROR in Stalwart logs (INFO level); Calendar/set commits cleanly.

Reproduction Steps

  1. As user A, share a calendar with user B from the web UI at “Read Items” or read-write level.
  2. Calendar/get (account A) → shareWith correctly lists B’s grant.
  3. Session (as B) → accounts does not include A.
  4. B does not see A’s calendar in any client.
  5. Inspect the store: SUBSPACE_ACL has no row for grant=B / owner=A / collection=08, even though A’s calendar archive contains the ACL.

Relevant Log Output

(INFO level: Calendar/set commits with no error; no store/JMAP/ACL warnings or errors.
PostgreSQL logs: no SQL error during the share.
Can re-run at trace level on request.)

Stalwart Version

v0.16.x

Installation Method

Docker

Database Backend

PostgreSQL

Blob Storage

S3-compatible

Search Engine

PostgreSQL

Directory Backend

OIDC

I have reviewed the documentation and FAQ and confirm that my issue is NOT addressed there.

on

I have searched this support forum (open and closed topics) and confirm this is not a duplicate.

on

I understand that topics in this category are triaged by a bot first but a human reply will follow up. If I’d prefer a human-only reply, I’ll add the no-ai tag to my topic.

on

2

I can’t reproduce it from a static read alone: the calendar update path does emit an ACL index value, and the diff that writes acl_grant / acl_revoke looks correct, so if SUBSPACE_ACL stays empty the failure is more specific than “the ACL write path is missing”, especially since you note an earlier share on the same instance has a correct row.

A trace-level log of the failing Calendar/set is exactly what I need: it’ll show whether the ACL diff branch runs and whether acl_grant is emitted. Also useful: the exact 0.16.x patch, the precise grant being set (which permission bits), and whether this calendar was created before an upgrade vs fresh on the current version, the working-earlier-share-vs-failing-new-ones pattern hints at a schema/migration difference.

3 
Additional data from a trace-level capture of the failing operation.

Environment

Stalwart v0.16.7, official Docker image stalwartlabs/stalwart:v0.16.7, fresh install - never upgraded

Data store: PostgreSQL 18.4. Blob store: S3. Full-text search: Postgresql. Directory: external OIDC.

JMAP webmail client.

Setup

Owner alice (account id 2), grantee bob (account id 1).

Calendar shared: alice’s calendar (JMAP accountId:“c”, calendar object id “b”, name “Calendrier (aliceATexample.org)”).

Permission set: mayReadFreeBusy:true, mayReadItems:true, all others false.

Request sent (Calendar/set)

{“accountId”:“c”,“update”:{“b”:{“shareWith/b”:{“mayReadFreeBusy”:true,“mayReadItems”:true,“mayWriteAll”:false,“mayWriteOwn”:false,“mayUpdatePrivate”:false,“mayRSVP”:false,“mayShare”:false,“mayDelete”:false}}}}

Response (Calendar/set)

{“accountId”:“c”,“newState”:“smy”,“updated”:{“b”:null}}

Log: store.data-write elapsed = 114ms, total = 8.

Subsequent Calendar/get on the same calendar

{“id”:“b”,“name”:“Calendrier (aliceATexample.org)”,“shareWith”:{“b”:{“mayReadFreeBusy”:true,“mayReadItems”:true,“mayWriteAll”:true,“mayWriteOwn”:true,“mayUpdatePrivate”:true,“mayRSVP”:true,“mayShare”:false,“mayDelete”:false}}, …}

ACL index (PostgreSQL table a, full dump after the operation)

key = 00000005 00000001 08 00000002val = 0000000000000409

This is the only row in the table. Key layout: grant_account_id(u32) | owner_account_id(u32) | collection(1B) | document_id(u32); collection 0x08 = Calendar; value = permission bitmap.

No row exists with grant=00000001 (bob), owner=00000002 (alice), collection 0x08.

traces:


```
2026-06-16T19:09:05Z TRACE HTTP request body (http.request-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, details = [["host", "mail.example.org"], ["x-real-ip", "203.0.113.10"], ["x-forwarded-for", "203.0.113.10"], ["x-forwarded-proto", "https"], ["content-length", "376"], ["user-agent", "Mozilla/5.0 (X11; Linux x86_64; rv:151.0) Gecko/20100101 Firefox/151.0"], ["accept", "*/*"], ["accept-language", "en-US,en;q=0.9"], ["accept-encoding", "gzip, deflate, br, zstd"], ["content-type", "application/json"], ["referer", "hxxps://webmail.example.org/"], ["origin", "hxxps://webmail.example.org"], ["sec-fetch-dest", "empty"], ["sec-fetch-mode", "cors"], ["sec-fetch-site", "same-site"], ["authorization", "Bearer ***REDACTED***"], ["dnt", "1"], ["sec-gpc", "1"], ["priority", "u=4"]], contents = "{"using":["urn_ietf_params:jmap:core","urn_ietf_params:jmap:calendars","urn_ietf_params:jmap:principals:owner"],"methodCalls":[["Calendar/get",{"accountId":"c","properties":["id","name","description","color","sortOrder","isSubscribed","isVisible","isDefault","includeInAvailability","defaultAlertsWithTime","defaultAlertsWithoutTime","timeZone","shareWith","myRights"]},"0"]]}", size = 376
2026-06-16T19:09:05Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) accountId = 2, collection = "calendar", changeId = 96, elapsed = 0ms
2026-06-16T19:09:05Z DEBUG JMAP method call (jmap.method-call) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Calendar/get", accountId = 2, elapsed = 0ms
2026-06-16T19:09:05Z TRACE HTTP response body (http.response-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, contents = "{"methodResponses":[["Calendar/get",{"accountId":"c","state":"sma","list":[{"id":"b","name":"Calendrier ([email protected])","description":null,"color":"#3b82f6","sortOrder":0,"isSubscribed":false,"isVisible":true,"isDefault":true,"includeInAvailability":"all","defaultAlertsWithTime":{},"defaultAlertsWithoutTime":{},"timeZone":null,"shareWith":{"b":{"mayReadFreeBusy":true,"mayReadItems":true,"mayWriteAll":true,"mayWriteOwn":true,"mayUpdatePrivate":true,"mayRSVP":true,"mayShare":false,"mayDelete":false}},"myRights":{"mayReadFreeBusy":true,"mayReadItems":true,"mayWriteAll":true,"mayWriteOwn":true,"mayUpdatePrivate":true,"mayRSVP":true,"mayShare":true,"mayDelete":true}}],"notFound":[]},"0"]],"sessionState":"48cce36b"}", code = 200, size = 727
2026-06-16T19:09:05Z DEBUG HTTP request URL (http.request-url) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 58862, remoteIp = 203.0.113.10, url = "/jmap/"
2026-06-16T19:09:05Z TRACE Expression evaluation result (eval.result) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 58862, id = "Http with id singleton", key = "allowedEndpoints", result = "Integer(200)"
2026-06-16T19:09:05Z TRACE HTTP response body (http.response-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 58862, contents = (null), code = 204, size = 0
2026-06-16T19:09:05Z DEBUG HTTP request URL (http.request-url) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, remoteIp = 203.0.113.10, url = "/jmap/"
2026-06-16T19:09:05Z TRACE Expression evaluation result (eval.result) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Http with id singleton", key = "allowedEndpoints", result = "Integer(200)"
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) key = 2, collection = "accessToken"
2026-06-16T19:09:05Z TRACE HTTP request body (http.request-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, details = [["host", "mail.example.org"], ["x-real-ip", "203.0.113.10"], ["x-forwarded-for", "203.0.113.10"], ["x-forwarded-proto", "https"], ["content-length", "259"], ["user-agent", "Mozilla/5.0 (X11; Linux x86_64; rv:151.0) Gecko/20100101 Firefox/151.0"], ["accept", "*/*"], ["accept-language", "en-US,en;q=0.9"], ["accept-encoding", "gzip, deflate, br, zstd"], ["content-type", "application/json"], ["referer", "hxxps://webmail.example.org/"], ["origin", "hxxps://webmail.example.org"], ["sec-fetch-dest", "empty"], ["sec-fetch-mode", "cors"], ["sec-fetch-site", "same-site"], ["authorization", "Bearer ***REDACTED***"], ["dnt", "1"], ["sec-gpc", "1"], ["priority", "u=4"]], contents = "{"using":["urn_ietf_params:jmap:core","urn_ietf_params:jmap:calendars","urn_ietf_params:jmap:principals:owner"],"methodCalls":[["CalendarEvent/query",{"accountId":"c","filter":{"after":"2026-06-16T00:00:00","before":"2026-07-16T23:59:59"},"limit":1000},"0"]]}", size = 259
2026-06-16T19:09:05Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) accountId = 2, collection = "calendar", changeId = 96, elapsed = 0ms
2026-06-16T19:09:05Z DEBUG JMAP method call (jmap.method-call) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "CalendarEvent/query", accountId = 2, elapsed = 0ms
2026-06-16T19:09:05Z TRACE HTTP response body (http.response-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, contents = "{"methodResponses":[["CalendarEvent/query",{"accountId":"c","queryState":"saq","canCalculateChanges":true,"position":0,"ids":[]},"0"]],"sessionState":"48cce36b"}", code = 200, size = 161
2026-06-16T19:09:05Z DEBUG HTTP request URL (http.request-url) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, remoteIp = 203.0.113.10, url = "/jmap/"
2026-06-16T19:09:05Z TRACE Expression evaluation result (eval.result) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Http with id singleton", key = "allowedEndpoints", result = "Integer(200)"
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) key = 2, collection = "accessToken"
2026-06-16T19:09:05Z TRACE HTTP request body (http.request-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, details = [["host", "mail.example.org"], ["x-real-ip", "203.0.113.10"], ["x-forwarded-for", "203.0.113.10"], ["x-forwarded-proto", "https"], ["content-length", "719"], ["user-agent", "Mozilla/5.0 (X11; Linux x86_64; rv:151.0) Gecko/20100101 Firefox/151.0"], ["accept", "*/*"], ["accept-language", "en-US,en;q=0.9"], ["accept-encoding", "gzip, deflate, br, zstd"], ["content-type", "application/json"], ["referer", "hxxps://webmail.example.org/"], ["origin", "hxxps://webmail.example.org"], ["sec-fetch-dest", "empty"], ["sec-fetch-mode", "cors"], ["sec-fetch-site", "same-site"], ["authorization", "Bearer ***REDACTED***"], ["dnt", "1"], ["sec-gpc", "1"], ["priority", "u=4"]], contents = "{"using":["urn_ietf_params:jmap:core","urn_ietf_params:jmap:calendars","urn_ietf_params:jmap:principals:owner"],"methodCalls":[["CalendarEvent/query",{"accountId":"c","filter":{"types":["Task"]},"limit":1000},"0"],["CalendarEvent/get",{"accountId":"c","properties":["id","@type","uid","calendarIds","title","description","descriptionContentType","created","updated","start","due","duration","timeZone","showWithoutTime","utcStart","utcEnd","progress","progressUpdated","priority","privacy","color","keywords","categories","recurrenceRule","recurrenceOverrides","excludedRecurrenceRule","useDefaultAlerts","alerts","relatedTo","percentComplete"],"#ids":{"resultOf":"0","name":"CalendarEvent/query","path":"/ids"}},"1"]]}", size = 719
2026-06-16T19:09:05Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) accountId = 2, collection = "calendar", changeId = 96, elapsed = 0ms
2026-06-16T19:09:05Z DEBUG Unsupported JMAP filter (jmap.unsupported-filter) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, details = "types", accountId = 2, causedBy = "CalendarEvent/query"
2026-06-16T19:09:05Z DEBUG Invalid JMAP result reference (jmap.invalid-result-reference) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, details = "Result reference to 0#CalendarEvent/query not found."
2026-06-16T19:09:05Z TRACE HTTP response body (http.response-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, contents = "{"methodResponses":[["error",{"type":"unsupportedFilter","description":"REDACTED"},"0"],["error",{"type":"invalidResultReference","description":"REDACTED"},"1"]],"sessionState":"48cce36b"}", code = 200, size = 229
2026-06-16T19:09:05Z DEBUG HTTP request URL (http.request-url) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, remoteIp = 203.0.113.10, url = "/jmap/"
2026-06-16T19:09:05Z TRACE Expression evaluation result (eval.result) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Http with id singleton", key = "allowedEndpoints", result = "Integer(200)"
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) key = 2, collection = "accessToken"
2026-06-16T19:09:05Z TRACE HTTP request body (http.request-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, details = [["host", "mail.example.org"], ["x-real-ip", "203.0.113.10"], ["x-forwarded-for", "203.0.113.10"], ["x-forwarded-proto", "https"], ["content-length", "376"], ["user-agent", "Mozilla/5.0 (X11; Linux x86_64; rv:151.0) Gecko/20100101 Firefox/151.0"], ["accept", "*/*"], ["accept-language", "en-US,en;q=0.9"], ["accept-encoding", "gzip, deflate, br, zstd"], ["content-type", "application/json"], ["referer", "hxxps://webmail.example.org/"], ["origin", "hxxps://webmail.example.org"], ["sec-fetch-dest", "empty"], ["sec-fetch-mode", "cors"], ["sec-fetch-site", "same-site"], ["authorization", "Bearer ***REDACTED***"], ["dnt", "1"], ["sec-gpc", "1"], ["priority", "u=4"]], contents = "{"using":["urn_ietf_params:jmap:core","urn_ietf_params:jmap:calendars","urn_ietf_params:jmap:principals:owner"],"methodCalls":[["Calendar/get",{"accountId":"e","properties":["id","name","description","color","sortOrder","isSubscribed","isVisible","isDefault","includeInAvailability","defaultAlertsWithTime","defaultAlertsWithoutTime","timeZone","shareWith","myRights"]},"0"]]}", size = 376
2026-06-16T19:09:05Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) accountId = 4, collection = "calendar", changeId = 5, elapsed = 0ms
2026-06-16T19:09:05Z DEBUG JMAP method call (jmap.method-call) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Calendar/get", accountId = 2, elapsed = 1ms
2026-06-16T19:09:05Z TRACE HTTP response body (http.response-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, contents = "{"methodResponses":[["Calendar/get",{"accountId":"e","state":"sau","list":[{"id":"b","name":"Calendrier ([email protected])","description":null,"color":null,"sortOrder":0,"isSubscribed":false,"isVisible":true,"isDefault":true,"includeInAvailability":"all","defaultAlertsWithTime":{},"defaultAlertsWithoutTime":{},"timeZone":null,"shareWith":{},"myRights":{"mayReadFreeBusy":true,"mayReadItems":true,"mayWriteAll":true,"mayWriteOwn":true,"mayUpdatePrivate":true,"mayRSVP":true,"mayShare":true,"mayDelete":true}}],"notFound":[]},"0"]],"sessionState":"48cce36b"}", code = 200, size = 562
2026-06-16T19:09:05Z DEBUG HTTP request URL (http.request-url) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, remoteIp = 203.0.113.10, url = "/jmap/"
2026-06-16T19:09:05Z TRACE Expression evaluation result (eval.result) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Http with id singleton", key = "allowedEndpoints", result = "Integer(200)"
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) key = 2, collection = "accessToken"
2026-06-16T19:09:05Z TRACE HTTP request body (http.request-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, details = [["host", "mail.example.org"], ["x-real-ip", "203.0.113.10"], ["x-forwarded-for", "203.0.113.10"], ["x-forwarded-proto", "https"], ["content-length", "259"], ["user-agent", "Mozilla/5.0 (X11; Linux x86_64; rv:151.0) Gecko/20100101 Firefox/151.0"], ["accept", "*/*"], ["accept-language", "en-US,en;q=0.9"], ["accept-encoding", "gzip, deflate, br, zstd"], ["content-type", "application/json"], ["referer", "hxxps://webmail.example.org/"], ["origin", "hxxps://webmail.example.org"], ["sec-fetch-dest", "empty"], ["sec-fetch-mode", "cors"], ["sec-fetch-site", "same-site"], ["authorization", "Bearer ***REDACTED***"], ["dnt", "1"], ["sec-gpc", "1"], ["priority", "u=4"]], contents = "{"using":["urn_ietf_params:jmap:core","urn_ietf_params:jmap:calendars","urn_ietf_params:jmap:principals:owner"],"methodCalls":[["CalendarEvent/query",{"accountId":"e","filter":{"after":"2026-06-16T00:00:00","before":"2026-07-16T23:59:59"},"limit":1000},"0"]]}", size = 259
2026-06-16T19:09:05Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) accountId = 4, collection = "calendar", changeId = 5, elapsed = 0ms
2026-06-16T19:09:05Z DEBUG JMAP method call (jmap.method-call) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "CalendarEvent/query", accountId = 2, elapsed = 0ms
2026-06-16T19:09:05Z TRACE HTTP response body (http.response-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, contents = "{"methodResponses":[["CalendarEvent/query",{"accountId":"e","queryState":"sau","canCalculateChanges":true,"position":0,"ids":[]},"0"]],"sessionState":"48cce36b"}", code = 200, size = 161
2026-06-16T19:09:05Z DEBUG HTTP request URL (http.request-url) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, remoteIp = 203.0.113.10, url = "/jmap/"
2026-06-16T19:09:05Z TRACE Expression evaluation result (eval.result) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Http with id singleton", key = "allowedEndpoints", result = "Integer(200)"
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) key = 2, collection = "accessToken"
2026-06-16T19:09:05Z TRACE HTTP request body (http.request-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, details = [["host", "mail.example.org"], ["x-real-ip", "203.0.113.10"], ["x-forwarded-for", "203.0.113.10"], ["x-forwarded-proto", "https"], ["content-length", "576"], ["user-agent", "Mozilla/5.0 (X11; Linux x86_64; rv:151.0) Gecko/20100101 Firefox/151.0"], ["accept", "*/*"], ["accept-language", "en-US,en;q=0.9"], ["accept-encoding", "gzip, deflate, br, zstd"], ["content-type", "application/json"], ["referer", "hxxps://webmail.example.org/"], ["origin", "hxxps://webmail.example.org"], ["sec-fetch-dest", "empty"], ["sec-fetch-mode", "cors"], ["sec-fetch-site", "same-site"], ["authorization", "Bearer ***REDACTED***"], ["dnt", "1"], ["sec-gpc", "1"], ["priority", "u=4"]], contents = "{"using":["urn_ietf_params:jmap:core","urn_ietf_params:jmap:calendars","urn_ietf_params:jmap:principals:owner"],"methodCalls":[["CalendarEvent/get",{"accountId":"c","ids":null,"properties":["id","@type","uid","calendarIds","title","description","descriptionContentType","created","updated","start","due","duration","timeZone","showWithoutTime","utcStart","utcEnd","progress","progressUpdated","priority","privacy","color","keywords","categories","recurrenceRule","recurrenceOverrides","excludedRecurrenceRule","useDefaultAlerts","alerts","relatedTo","percentComplete"]},"0"]]}", size = 576
2026-06-16T19:09:05Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) accountId = 2, collection = "calendar", changeId = 96, elapsed = 0ms
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) key = 2, collection = "account"
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) key = 1, collection = "domainId"
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) key = 4, collection = "account"
2026-06-16T19:09:05Z DEBUG Cache hit (store.cache-hit) key = 1, collection = "domainId"
2026-06-16T19:09:05Z DEBUG JMAP method call (jmap.method-call) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "CalendarEvent/get", accountId = 2, elapsed = 0ms
2026-06-16T19:09:05Z TRACE HTTP response body (http.response-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, contents = "{"methodResponses":[["CalendarEvent/get",{"accountId":"c","state":"saq","list":[],"notFound":[]},"0"]],"sessionState":"48cce36b"}", code = 200, size = 129
2026-06-16T19:09:09Z DEBUG HTTP request URL (http.request-url) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, remoteIp = 203.0.113.10, url = "/jmap/"
2026-06-16T19:09:09Z TRACE Expression evaluation result (eval.result) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Http with id singleton", key = "allowedEndpoints", result = "Integer(200)"
2026-06-16T19:09:09Z DEBUG Cache hit (store.cache-hit) key = 2, collection = "accessToken"
2026-06-16T19:09:09Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:09Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:09Z DEBUG Cache hit (store.cache-hit) key = 1, collection = "account"
2026-06-16T19:09:09Z DEBUG Cache hit (store.cache-hit) key = 2, collection = "account"
2026-06-16T19:09:09Z DEBUG Cache hit (store.cache-hit) key = 3, collection = "account"
2026-06-16T19:09:09Z DEBUG Cache hit (store.cache-hit) key = 4, collection = "account"
2026-06-16T19:09:09Z DEBUG Cache hit (store.cache-hit) key = 5, collection = "account"
2026-06-16T19:09:09Z DEBUG Cache hit (store.cache-hit) key = 6, collection = "account"
2026-06-16T19:09:09Z DEBUG Cache hit (store.cache-hit) key = 7, collection = "account"
2026-06-16T19:09:09Z DEBUG Cache hit (store.cache-hit) key = 8, collection = "account"
2026-06-16T19:09:09Z DEBUG Cache hit (store.cache-hit) key = 9, collection = "account"
2026-06-16T19:09:11Z DEBUG HTTP request URL (http.request-url) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, remoteIp = 203.0.113.10, url = "/jmap/"
2026-06-16T19:09:11Z TRACE Expression evaluation result (eval.result) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Http with id singleton", key = "allowedEndpoints", result = "Integer(200)"
2026-06-16T19:09:11Z TRACE HTTP response body (http.response-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, contents = (null), code = 204, size = 0
2026-06-16T19:09:11Z DEBUG HTTP request URL (http.request-url) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, remoteIp = 203.0.113.10, url = "/jmap/"
2026-06-16T19:09:11Z TRACE Expression evaluation result (eval.result) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Http with id singleton", key = "allowedEndpoints", result = "Integer(200)"
2026-06-16T19:09:11Z DEBUG Cache hit (store.cache-hit) key = 2, collection = "accessToken"
2026-06-16T19:09:11Z TRACE HTTP request body (http.request-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, details = [["host", "mail.example.org"], ["x-real-ip", "203.0.113.10"], ["x-forwarded-for", "203.0.113.10"], ["x-forwarded-proto", "https"], ["content-length", "203"], ["user-agent", "Mozilla/5.0 (X11; Linux x86_64; rv:151.0) Gecko/20100101 Firefox/151.0"], ["accept", "*/*"], ["accept-language", "en-US,en;q=0.9"], ["accept-encoding", "gzip, deflate, br, zstd"], ["content-type", "application/json"], ["referer", "hxxps://webmail.example.org/"], ["origin", "hxxps://webmail.example.org"], ["sec-fetch-dest", "empty"], ["sec-fetch-mode", "cors"], ["sec-fetch-site", "same-site"], ["authorization", "Bearer ***REDACTED***"], ["dnt", "1"], ["sec-gpc", "1"], ["priority", "u=0"]], contents = "{"using":["urn_ietf_params:jmap:core","urn_ietf_params:jmap:calendars","urn_ietf_params:jmap:principals:owner"],"methodCalls":[["Calendar/set",{"accountId":"c","update":{"b":{"shareWith/b":null}}},"0"]]}", size = 203
2026-06-16T19:09:11Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:11Z DEBUG Cache hit (store.cache-hit) accountId = 2, collection = "calendar", changeId = 96, elapsed = 0ms
2026-06-16T19:09:11Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:11Z TRACE Write batch operation (store.data-write) elapsed = 34ms, total = 8
2026-06-16T19:09:11Z DEBUG JMAP method call (jmap.method-call) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Calendar/set", accountId = 2, elapsed = 35ms
2026-06-16T19:09:11Z TRACE HTTP response body (http.response-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, contents = "{"methodResponses":[["Calendar/set",{"accountId":"c","newState":"smu","updated":{"b":null}},"0"]],"sessionState":"48cce36b"}", code = 200, size = 124
2026-06-16T19:09:11Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:16Z DEBUG HTTP request URL (http.request-url) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, remoteIp = 203.0.113.10, url = "/jmap/"
2026-06-16T19:09:16Z TRACE Expression evaluation result (eval.result) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Http with id singleton", key = "allowedEndpoints", result = "Integer(200)"
2026-06-16T19:09:16Z DEBUG Cache hit (store.cache-hit) key = 2, collection = "accessToken"
2026-06-16T19:09:16Z TRACE HTTP request body (http.request-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, details = [["host", "mail.example.org"], ["x-real-ip", "203.0.113.10"], ["x-forwarded-for", "203.0.113.10"], ["x-forwarded-proto", "https"], ["content-length", "359"], ["user-agent", "Mozilla/5.0 (X11; Linux x86_64; rv:151.0) Gecko/20100101 Firefox/151.0"], ["accept", "*/*"], ["accept-language", "en-US,en;q=0.9"], ["accept-encoding", "gzip, deflate, br, zstd"], ["content-type", "application/json"], ["referer", "hxxps://webmail.example.org/"], ["origin", "hxxps://webmail.example.org"], ["sec-fetch-dest", "empty"], ["sec-fetch-mode", "cors"], ["sec-fetch-site", "same-site"], ["authorization", "Bearer ***REDACTED***"], ["dnt", "1"], ["sec-gpc", "1"], ["priority", "u=0"]], contents = "{"using":["urn_ietf_params:jmap:core","urn_ietf_params:jmap:calendars","urn_ietf_params:jmap:principals:owner"],"methodCalls":[["Calendar/set",{"accountId":"c","update":{"b":{"shareWith/b":{"mayReadFreeBusy":true,"mayReadItems":true,"mayWriteAll":false,"mayWriteOwn":false,"mayUpdatePrivate":false,"mayRSVP":false,"mayShare":false,"mayDelete":false}}}},"0"]]}", size = 359
2026-06-16T19:09:16Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:16Z DEBUG Cache update (store.cache-update) accountId = 2, collection = "calendar", changeId = 101, details = 1, total = 1, elapsed = 1ms
2026-06-16T19:09:16Z TRACE Data store iteration operation (store.data-iterate) elapsed = 0ms
2026-06-16T19:09:16Z TRACE Write batch operation (store.data-write) elapsed = 114ms, total = 8
2026-06-16T19:09:16Z DEBUG JMAP method call (jmap.method-call) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, id = "Calendar/set", accountId = 2, elapsed = 116ms
2026-06-16T19:09:16Z TRACE HTTP response body (http.response-body) listenerId = "https", localPort = 443, remoteIp = 10.0.0.2, remotePort = 50704, contents = "{"methodResponses":[["Calendar/set",{"accountId":"c","newState":"smy","updated":{"b":null}},"0"]],"sessionState":"48cce36b"}", code = 200, size = 124

```