Firestore listener stops receiving changes after a long time running without throwing an error

[AndersonHappens]

[READ] Step 1: Are you in the right place?

• For issues or feature requests related to the code in this repository
  file a Github issue.
  • If this is a feature request make sure the issue title starts with "FR:".
• For general technical questions, post a question on StackOverflow
  with the firebase tag.
• For general Firebase discussion, use the firebase-talk
  google group.
• For help troubleshooting your application that does not fall under one
  of the above categories, reach out to the personalized
  Firebase support channel.

[REQUIRED] Step 2: Describe your environment

• Operating System version: Windows 10
• Firebase SDK version: 6.10.0
• Library version: firebase-admin: 2.16.0
• Firebase Product: firestore

[REQUIRED] Step 3: Describe the problem

Steps to reproduce:

After running a firebase listener for a long time (4-14) days and restarting the listener every time it closes due to the other issue, (#282), eventually the listener will stop receiving changes all together. This is not the internet connection issue (#287) as I tried testing it after an internet disconnection for 1 minute and both listeners kept receiving changes and after 5 minutes both listeners I had running restarted due to "None stream".

I have tried debugging the listener after it stops working, but the _closed variable is still false and all other class variables are still normal (is_active is true, had_pushed is true). It seems to be random chance though, because of the two listeners I have, one of them never stops receiving changes while the other one will after a long time. The only real difference I have between the two is that I call time.sleep in the one that stops receiving input and I don't in the other listener. I will keep debugging and see if that's the issue, but I doubt it.

Relevant Code:

The code has the same structure as this:

class TestWatchInfo():
  def __init__(self):
    self.start_snapshot()

  def start_snapshot(self):
    self.query_watch = db.collection(u'info').on_snapshot(self.on_snapshot)

  def on_snapshot(self, col_snapshot, changes, read_time):
    try:
      for change in changes:
        # do lots of stuff here that can take up to a minute to complete
        # including writes, deletes, and reads from the database
        time.sleep(60)
    except Exception as err:
      print(err)
      print("Error occurred at " + str(time.ctime()))
      traceback.print_exc()

if __name__ == '__main__':
  try:
    test_object = TestWatchInfo()
    while(True):
      if test_object.query_watch._closed:
        test_object.start_snapshot()
      # code here
  except Exception as err:
    print(err)
    print("Error occurred at " + str(time.ctime()))
    traceback.print_exc()

[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.

[AndersonHappens]

I'm pretty sure that sleep isn't the issue. It works normally in the snapshot. Firestore will still catch changes that are made consecutively while the thread is sleeping and will wait for the thread to finish before updating the next changes just fine. I also tested updating firestore while both the main thread and the snapshot thread were paused in a debugger (to simulate them sleeping simultaneously) and it caught the updates just fine and continued to run. The annoying part about this bug is that there are no logs or errors thrown anywhere for me to check and debug - the listener just stops receiving updates (I check by seeing if the listener propagates those updates to other parts of the firestore database)

[hiranya911]

@tseaver @BenWhitehead can you take a look?

[AndersonHappens]

Status update on this? I'm just manually restarting the listener every hour to get around this currently.

[BenWhitehead]

@crwilcox Any insight you might be able to add here? This is out of my depth.

[eambutu]

I get this bug too: the listener just stops getting changes and the .closed flag is still false. One thing I've noticed is that when I restart the server, all the changes it missed come in at once. Right now our workaround is to use a cron job to restart the server every hour, but it would be nice to know the actual fix to this.

[linevych]

I have the same issue and used the same workaround. I have a thread that checks watch._closed in the infinite loop every 0.1 second. Any update on when this will be fixed?

[MilkyWayGalaxyUser]

same ISSUE!

[doylep]

Writing to confirm that this issue is still out in the wild. Is there a recommended workaround?

[BenWhitehead]

Ongoing work to figure out the root cause of this issues is happening over on googleapis/python-firestore#18. As of now, there is not a known reliable work around.

[doylep]

Thanks for the update. I will resort to restarting the call every minute for now.

[schmidt-sebastian]

Closing this as we will continue to track the progress in googleapis/python-firestore#18