Connection fails and never recovers

[carterbs]

[REQUIRED] Describe your environment

• Operating System version: MacOS 12.5
• Browser version: Chromium 100
• Firebase SDK version: 9.9
• Firebase Product: realtime database

[REQUIRED] Describe the problem

When changing connections, it's possible to get firebase into a 'stuck' state where all requests return datastale, and transactions error out with error maxretry.

Steps to reproduce:

This is reproducible roughly 65% of the time.

Steps:

Requires a wired connection and a wireless card.

1. Connect your computer to your wired internet. Start your app.
2. Pull the plug and start walking away from your router.
3. Try some action that requires a realtime database transaction.
4. Observe Error: maxretry

I know that this is an incredibly contrived example, but I also believe this can happen on an unstable 4g hotspot connection. The steps above are the only way I could reliably get it to happen. Here are some relevant logs:

[2022-08-10 14:12:10.573] [info] @firebase/database: c:0:0:0 WebSocket error.  Closing connection. 
[2022-08-10 14:12:10.573] [info] @firebase/database: c:0:0:0 Network error: wss:[REDACTED]: read ETIMEDOUT 
[2022-08-10 14:12:10.574] [info] @firebase/database: c:0:0:0 WebSocket is closing itself 
[2022-08-10 14:12:10.574] [info] @firebase/database: c:0:0: Realtime connection lost. 
[2022-08-10 14:12:10.575] [info] @firebase/database: c:0:0: Closing realtime connection. 
[2022-08-10 14:12:10.575] [info] @firebase/database: c:0:0: Shutting down all connections 
[2022-08-10 14:12:10.575] [info] @firebase/database: p:0: data client disconnected 
[2022-08-10 14:12:10.581] [info] @firebase/database: 0: onDisconnectEvents 
[2022-08-10 14:12:10.582] [info] @firebase/database: c:0:0:0 Websocket connection was disconnected. 
[2022-08-10 14:12:10.583] [info] @firebase/database: p:0: Making a connection attempt 
[2022-08-10 14:12:10.584] [info] @firebase/database: getToken() completed. Creating connection. 
[2022-08-10 14:12:10.585] [info] @firebase/database: c:0:1: Connection created 
[2022-08-10 14:12:10.586] [info] @firebase/database: c:0:1:0 Websocket connecting to wss:[REDACTED]
[2022-08-10 14:12:10.746] [info] @firebase/database: c:0:1:0 Websocket connected. 
[2022-08-10 14:12:10.749] [info] @firebase/database: c:0:1: Realtime connection established. 
[2022-08-10 14:12:10.749] [info] @firebase/database: p:0: connection ready 
[2022-08-10 14:12:10.752] [info] @firebase/database: event: /.info/connected:value:true 
[2022-08-10 14:12:10.799] [info] @firebase/database: c:0:1: Primary connection is healthy. 
[2022-08-10 14:12:10.800] [info] @firebase/database: p:0: from server: {"r":23,"b":{"s":"ok","d":{}}} 
[2022-08-10 14:12:10.800] [info] @firebase/database: p:0: listen response {"s":"ok","d":{}} 
[2022-08-10 14:12:10.801] [info] @firebase/database: p:0: from server: {"r":24,"b":{"s":"ok","d":""}} 
[2022-08-10 14:12:10.801] [info] @firebase/database: p:0: p response {"s":"ok","d":""} 
[2022-08-10 14:12:10.801] [info] @firebase/database: p:0: from server: {"r":25,"b":{"s":"datastale","d":"Transaction ETag does not match"}} 
[2022-08-10 14:12:10.801] [info] @firebase/database: p:0: p response {"s":"datastale","d":"Transaction ETag does not match"} 
[2022-08-10 14:12:10.801] [info] @firebase/database: 0: transaction put response {"path":"[REDACTED]","status":"datastale"} 
[2022-08-10 14:12:10.802] [info] @firebase/database: p:0: from server: {"r":26,"b":{"s":"ok","d":""}} 
[2022-08-10 14:12:10.802] [info] @firebase/database: p:0: p response {"s":"ok","d":""} 
[2022-08-10 14:12:10.802] [info] @firebase/database: p:0: from server: {"r":27,"b":{"s":"ok","d":""}} 
[2022-08-10 14:12:10.802] [info] @firebase/database: p:0: p response {"s":"ok","d":""} 
[2022-08-10 14:12:20.965] [warn] @firebase/firestore: Firestore (9.9.0): Connection GRPC stream error. Code: 14 Message: 14 UNAVAILABLE: read ETIMEDOUT

---This gap is from our app; it takes a while to restart a connection; part of that connection is running a transaction---


[2022-08-10 14:12:34.675] [info] @firebase/database: p:0: from server: {"r":28,"b":{"s":"datastale","d":"Transaction ETag does not match"}} 
[2022-08-10 14:12:34.676] [info] @firebase/database: p:0: p response {"s":"datastale","d":"Transaction ETag does not match"} 
[2022-08-10 14:12:34.677] [info] @firebase/database: p:0: {"r":29,"a":"p","b":{"p":"[REDACTED]","d":{"start":1660155130587,"stop":{".sv":"timestamp"}},"h":"[REDACTED]"}} 
[2022-08-10 14:12:34.716] [info] @firebase/database: p:0: from server: {"r":29,"b":{"s":"datastale","d":"Transaction ETag does not match"}} 
[2022-08-10 14:12:34.716] [info] @firebase/database: p:0: p response {"s":"datastale","d":"Transaction ETag does not match"} 
[2022-08-10 14:12:34.716] [info] @firebase/database: 0: transaction put response {"path":[REDACTED],"status":"datastale"} 

The put request + datastale runs 25 times (maxretry), then the request errors out. It keeps doing this until you restart our application, which creates a new Database object.

[google-oss-bot]

I couldn't figure out how to label this issue, so I've labeled it for a human to triage. Hang tight.

[maneesht]

@carterbs thank you for the verbose logging. Are you able to reproduce this using the Offline capability in the Network tab in Chrome?

[carterbs]

I cannot - the transaction mysteriously completes. Or at least, the promise that invokes the transaction completes.

[glennweb]

+1

[carterbs]

Bump. @maneesht have you been able to look at this?

[maneesht]

@carterbs - I've tried to reproduce by changing wi-fi networks in the middle of the transaction, but was unsuccessful. I will try and reproduce using wired -> wireless and will get back to you.

[carterbs]

Thanks a lot! This happened again to me today (it's happened before, but others asked me what was going on), and sure enough the max-retry error was in the logs. Had to restart the app to get it to work again (and establish a new connection and all of that).

[maneesht]

@carterbs can you also provide some more information on your use-case?

1. When you start the app, you are online, and are you currently running a transaction, and in the middle of that transaction, you remove the wired connection and step away from your router?
2. When you say step away from your router, do you mean go completely offline?

[carterbs]

1. Online, everything's groovy. I connect, which runs a transaction. Transaction is complete. No transactions happening in the background.
2. I pull out my wired connection because I drank 20oz of water and my bladder is full. My computer starts to switch to wireless at this point.
3. Computer is connecting to wireless. I lose the connection to firebase.
4. I connect to wireless and try to connect again, which runs a transaction. Transaction never completes. I get maxretry errors in the logs until I reboot the app and create new firebase objects (presumably that's what fixes it).

You can wait as long as you want and you'll just keep getting maxretry errors. Only thing I've found that fixes it is a reboot of the app.

By step away from the router I mean physically distance yourself so the wireless signal is weaker. That part is all speculation, but it's what happens when I leave my office and head to my house for a bathroom break.

[maneesht]

@carterbs - thank you for the thorough response! Just want to make sure that I follow your exact repo and am not missing anything. Will keep you posted.

[Slimkiller21]

once the writeData function is actioned i get this error:

WebSocketConnection.ts:47 GET https://database_name.firebaseio.com.firebaseio.com/.lp?start=t&ser=34054904&cb=6&v=5&p=1:165155012476:web:94207d8b96cc0f2785aef9&ns=database_name net::ERR_CERT_COMMON_NAME_INVALID

and it repeats itself several times, can anyone help???

[tanner1993]

I believe I am also experiencing this issue, it happens to me once every few weeks probly when I'm going from LTE to wifi of my house. It's a terrible user experience and I feel like there has to be a way to somehow restart Firebase without killing the app but killing the app is the only solution I can find so far

[HazzMan2409]

On the off-chance this helps someone... this isn't the same bug as what the OP is on about (as the timelines don't match and it affects Chromium) but there is a very similar bug in WebKit that I think readers of this bug might be experiencing https://bugs.webkit.org/show_bug.cgi?id=247943