Skip to content

A share's notification is lost for good when userlog's store write fails, because the event was acknowledged before userlog processed it #13264

Open

Description

@miaoti

Describe the bug

When userlog cannot store an event for a user, the notification is lost for good. The share is created (OCS 200) and auto-accepted, so the frontend's consumer got the event, but the recipient never sees the notification. userlog logs failed to store event for user and moves on, and the message is never delivered again, because it was acknowledged before userlog started to work on it.

At v8.2.2 (identical on master on 2026-10-28) the ack happens at hand-off. reva's events.Consume subscribes with only a group (L97), so go-micro's natsjs plugin uses an explicit-ack subscription and returns once the event is handed to a channel (L183-L198). nats.go then acknowledges a callback subscription itself when the callback returns (L1932-L1936), and reva re-wraps the event without the plugin's ack callbacks (L108-L134). On a failed write userlog's processEvent only logs and returns (L212-L217). eventhistory does the same (L62-L73). Neither has a retry or a replay.

Steps to reproduce

Single binary 8.2.2 (release asset ocis-8.2.2-linux-amd64) and the nats CLI. The default userlog store is memory, so use the NATS KV store as the chart does. E and M hold user:pass of the demo users einstein and marie, as listed in the admin documentation, section Demo Users and Groups.

export OCIS_INSECURE=true PROXY_ENABLE_BASIC_AUTH=true IDM_CREATE_DEMO_USERS=true
export OCIS_PERSISTENT_STORE=nats-js-kv OCIS_PERSISTENT_STORE_NODES=127.0.0.1:9233
ocis init && ocis server   # NATS listens on 127.0.0.1:9233 without authentication

In a second shell:

H=https://localhost:9200
N="nats --server nats://127.0.0.1:9233"
up() {
  curl -sk -u "$E" -T /etc/hostname -D - -o /dev/null "$H/remote.php/webdav/$1"
  sleep 3
}
share() {
  curl -sk -u "$E" -X POST "$H/ocs/v2.php/apps/files_sharing/api/v1/shares?format=json" \
    -d path=/$1 -d shareType=0 -d shareWith=marie -d permissions=1
}
notes() ( curl -sk -u "$M" "$H/ocs/v2.php/apps/notifications/api/v1/notifications?format=json" )
mine() ( curl -sk -u "$M" "$H/ocs/v2.php/apps/files_sharing/api/v1/shares?shared_with_me=true&state=all&format=json" )
  1. up a.txt, then share a.txt. After 5 s notes has an item whose object_id is the OC-FileId of a.txt. KV_userlog exists after this write.
  2. up b.txt. Take the size in bytes from $N stream info KV_userlog and run $N stream edit KV_userlog --max-bytes=<bytes>, so that the stream (discard new) refuses writes that grow it. The CLI warns that editing the stream of a KV bucket is unsupported and asks twice for confirmation (Really operate on the KV stream?, then Really edit Stream KV_userlog), so run it in a terminal and answer y to both. With -f it asks once.
  3. share b.txt answers OCS 200 and mine shows "state":0. The ocis log has an error line of service userlog: message failed to store event for user, error Failed to store data in bucket '...': nats: maximum bytes exceeded (the quoted name is the encoded key of the user's list).
  4. Remove the cap (same prompts): $N stream edit KV_userlog --max-bytes=-1.
  5. After a minute and again later, notes has no item for b.txt, and $N consumer info main-queue userlog shows no outstanding acks and no redeliveries.

Expected behavior

A failed store write leaves the message unacknowledged or negatively acknowledged, so NATS delivers it again and userlog stores it once the write works. A possible fix: subscribe with nats.ManualAck(), pass the callbacks on through events.Consume, and ack after the store write succeeded, or nak with a delay.

Actual behavior

In three runs on Kubernetes (official chart, one pod per service), 9 shares created while KV_userlog refused writes all answered OCS 200 and were accepted (state 0), and userlog logged failed to store event for user for each. None of them reached the recipient's notification list, neither in 16 reads up to 38 s after the cap was removed nor 6 to 17 minutes later, after restarts of userlog and sharing (NATS was not restarted). The userlog consumer on main-queue showed ack_pending 0 and redelivered 0 throughout. 9 normal shares next to them were listed at the first read, 5 s after the share.

Setup

OCIS image owncloud/ocis:8.2.2 (sha256:08639361baa55e21037442daed4d8aa1a4fc4f2f12d06db92455a14782c29f61)
Helm chart owncloud/ocis-charts charts/ocis 0.8.0, features.demoUsers=true, replicas 1
NATS: the chart's own nats service
OCIS_PERSISTENT_STORE=nats-js-kv (set by the chart)
PROXY_ENABLE_BASIC_AUTH=true

The numbers come from that deployment, with 18 services running (the share path plus an auth-basic service, which the chart does not deploy), where the cap was set through the stream-update API. The single-binary steps above were also run once in a container of the same image, with the same outcome.

Additional context

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions