erquhart
erquhart2y ago

Sluggish reactivity

So I haven't fully dug into this for reproducibility and whatnot, but wanted to raise it and see if maybe there's a known issue here. I'm finding that there are seemingly random slowdowns in reactive updates of some queries. It looks like this: 1. Update something 2. Observe convex logs immediately processing both the update and dependent queries with consistent execution times 3. Observe dependent updates sometimes being instant, and sometimes taking as much as 8-10 seconds I should also note that this is React Native and I'm only target iOS atm, so no web builds. Using expo and expo tooling, I don't have a great way to observe websocket messages, which adds to the mystery here. Again, I haven't isolated and I can't stop and focus down on perf just yet, but it's really starting to stand out. I think I can say the following with certainty: 1. The request to convex and convex execution time is all working great based on logs 2. Individual queries are taking a consistent amount of time regardless of how performant they may or may not be (one in question takes about 250ms) 3. React native rendering performance seems really unlikely to be the issue as the delays are quite random, something I've never observed in the RN perf issues I've debugged as they're generally specific in source and relatively consistent. It feels like the issue is somewhere between Convex completing reruns of dependent queries on the backend and triggering renders of components utilizing these queries in the client. I'm checking for updates right at the convex hooks, before rendering even starts. The delay is between the successful convex log and the useQuery hook triggering a re-render.
6 Replies
ballingt
ballingt2y ago
Are there any patterns where e.g. you see this when the React Native app is inactive, as though the WebSocket might be reconnecting? and then updates after that are fast?
ballingt
ballingt2y ago
Could you set verbose: true, reportDebugInfoToConvex: true in the constructor of you Convex client? This might give us some visibility here https://docs.convex.dev/api/interfaces/browser.ClientOptions#reportdebuginfotoconvex
ballingt
ballingt2y ago
the verbose part might let you see the websocket messages being received in the react native app (assuming you have a way to view these logs?)
erquhart
erquhartOP2y ago
I'll do that. I don't believe it's an active/inactive thing, I can hit a toggle that updates data back and forth and get these different rendering delay times repeatedly. Everything should be active. But yeah, will make that change. It looks like the pattern is Mutation -> MutationResponse -> Transition, the update is rendered at roughly the same time that the Transition log is printed. Here's a sample with a fast turnaround and no delay:
DEBUG 2023-08-24T21:48:53.453Z sending message with type Mutation
DEBUG 2023-08-24T21:48:53.578Z received ws message with type MutationResponse
DEBUG 2023-08-24T21:48:53.955Z received ws message with type Transition
DEBUG 2023-08-24T21:48:53.453Z sending message with type Mutation
DEBUG 2023-08-24T21:48:53.578Z received ws message with type MutationResponse
DEBUG 2023-08-24T21:48:53.955Z received ws message with type Transition
Here's a sample that took ~5s without any obvious abnormality:
DEBUG 2023-08-24T21:48:55.021Z sending message with type Mutation
DEBUG 2023-08-24T21:48:55.180Z received ws message with type MutationResponse
DEBUG 2023-08-24T21:49:00.566Z received ws message with type Transition
DEBUG 2023-08-24T21:48:55.021Z sending message with type Mutation
DEBUG 2023-08-24T21:48:55.180Z received ws message with type MutationResponse
DEBUG 2023-08-24T21:49:00.566Z received ws message with type Transition
Here's a sample that took much longer (~11s) and had to reconnect:
DEBUG 2023-08-24T21:44:04.268Z sending message with type Mutation
DEBUG 2023-08-24T21:44:04.403Z received ws message with type MutationResponse
DEBUG 2023-08-24T21:44:15.337Z received ws message with type Transition
DEBUG 2023-08-24T21:44:15.399Z begin ws.onclose
LOG Attempting reconnect in 63.42258505463237ms
DEBUG 2023-08-24T21:44:15.476Z constructed WebSocket
DEBUG 2023-08-24T21:44:15.622Z begin ws.onopen
DEBUG 2023-08-24T21:44:15.623Z sending message with type Connect
DEBUG 2023-08-24T21:44:15.624Z sending message with type Authenticate
DEBUG 2023-08-24T21:44:15.624Z sending message with type ModifyQuerySet
LOG WebSocket reconnected
DEBUG 2023-08-24T21:44:15.836Z received ws message with type Transition
DEBUG 2023-08-24T21:44:16.290Z received ws message with type Transition
DEBUG 2023-08-24T21:44:04.268Z sending message with type Mutation
DEBUG 2023-08-24T21:44:04.403Z received ws message with type MutationResponse
DEBUG 2023-08-24T21:44:15.337Z received ws message with type Transition
DEBUG 2023-08-24T21:44:15.399Z begin ws.onclose
LOG Attempting reconnect in 63.42258505463237ms
DEBUG 2023-08-24T21:44:15.476Z constructed WebSocket
DEBUG 2023-08-24T21:44:15.622Z begin ws.onopen
DEBUG 2023-08-24T21:44:15.623Z sending message with type Connect
DEBUG 2023-08-24T21:44:15.624Z sending message with type Authenticate
DEBUG 2023-08-24T21:44:15.624Z sending message with type ModifyQuerySet
LOG WebSocket reconnected
DEBUG 2023-08-24T21:44:15.836Z received ws message with type Transition
DEBUG 2023-08-24T21:44:16.290Z received ws message with type Transition
ballingt
ballingt2y ago
Thanks, this is helpful data @erquhart do you remember what the dashboard logs look like for one of the above sessions; in addition to the query execution times being fast, do the timestamps show the mutation and the queries right after each other?
erquhart
erquhartOP2y ago
Yes, they all happen right away consistently Actually I'm watching production now and I'm not so sure I'm seeing some instances where there's a super long delay - guessing that's a websocket reconnect - and then more queries come after the delay, but the initial queries still go through initially so I think these are just due to the reconnect

Did you find this page helpful?