Google-cloud-dotnet: Firestore: The datastore operation timed out, or the data was temporarily unavailable

[skjagini]

Environment details

• OS: Tested on both Linux and Windows 10
• .NET version: .Net Core 2.0
• Package name and version: Google.Cloud.Firestore, Version 1.1.0 (latest stable release)

Steps to reproduce

• Fails to query when the property happens to be boolean, works fine if the property is string for example
• Tested on Firestore Emulator with boolean property and it works just fine.
• Tested the same code base running on .Net Core in Linux Container in GCP Kubernetes and it timesout. Tried connecting to the GCP Firestore from local debuger (windows 10) as well without much success.

       CollectionReference FoosRef = FirestoreDb.Collection(FooKind);
        Query query = FoosRef.WhereEqualTo("IsGoodFoo", true);
        // QuerySnapshot querySnapshot = await query.Offset(offset).GetSnapshotAsync();
       // Searching for String property works. 
        // Query query = FoosRef.WhereEqualTo("FooName", "p,ezbnR33GU_");
        QuerySnapshot querySnapshot = await query.GetSnapshotAsync();
        DocumentSnapshot documentSnapshot = querySnapshot.Documents.FirstOrDefault();

In the interim is there any other way to query for Boolean property with Offset to skip, please suggest.

Stack Trace:

Grpc.Core.RpcException: Status(StatusCode=Unavailable, Detail="The datastore operation timed out, or the data was temporarily unavailable.")
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Grpc.Core.Internal.ClientResponseStream`2.<MoveNext>d__5.MoveNext() in T:\src\github\grpc\src\csharp\Grpc.Core\Internal\ClientResponseStream.cs:line 61
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Linq.AsyncEnumerable.<ForEachAsync_>d__174`1.MoveNext() in D:\a\1\s\Ix.NET\Source\System.Interactive.Async\ForEach.cs:line 141
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Google.Cloud.Firestore.Query.<GetSnapshotAsync>d__54.MoveNext() in T:\src\github\google-cloud-dotnet\releasebuild\apis\Google.Cloud.Firestore\Google.Cloud.Firestore\Query.cs:line 619
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at FooLib.Library.FirestoreMappings.FooFirestore.<GetNextUnparsedFooInfo>d__4.MoveNext() in C:\Foo\FooLibFirestore\FooLib.Library\FirestoreMappings\FooFirestore.cs:line 51
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at FooLib.Library.Repositories.FooRepository.<GetNextUnparsedFooInfo>d__9.MoveNext() in C:\Foo\FooLibFirestore\FooLib.Library\Repositories\FooRepository.cs:line 102
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter`1.GetResult()
   at FooLib.WebApi.Controllers.FoosController.<GetNextUnparsedFooInfo>d__8.MoveNext() in C:\Foo\FooLibFirestore\FooLib.WebApi\Controllers\FoosController.cs:line 83
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at lambda_method(Closure , Object )
   at Microsoft.Extensions.Internal.ObjectMethodExecutorAwaitable.Awaiter.GetResult()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeActionMethodAsync>d__12.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeNextActionFilterAsync>d__10.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(ActionExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.<InvokeInnerFilterAsync>d__14.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.<InvokeNextResourceFilter>d__22.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow(ResourceExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.<InvokeFilterPipelineAsync>d__17.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.<InvokeAsync>d__15.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.Builder.RouterMiddleware.<Invoke>d__4.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at Microsoft.AspNetCore.Diagnostics.DeveloperExceptionPageMiddleware.<Invoke>d__7.MoveNext()

Making sure to follow these steps will guarantee the quickest resolution possible.

Thanks!

[jskeet]

Thanks for the report - I'll look into it tomorrow.

[jskeet]

In the meantime, if you could tell me what you're observing, that would help. Does the code show an exception? Fail to find anything? Fail to filter out anything?

[skjagini]

I am trying to filter a collection based on a Property (of type boolean) and the query times out instead of finding the document

I updated the original with stack trace.

[jskeet]

That's very helpful, thanks.

[jskeet]

I can't currently reproduce this. Here's a console application which sounds like it's doing what your code is doing

using Google.Cloud.Firestore;
using System;
using System.Threading.Tasks;

class Program
{
    static async Task Main(string[] args)
    {
        var db = FirestoreDb.Create(args[0]);

        var collection = db.Collection(Guid.NewGuid().ToString());

        await collection.AddAsync(new { Name = "First true entry", Include = true });
        await collection.AddAsync(new { Name = "First false entry", Include = false });
        await collection.AddAsync(new { Name = "Second true entry", Include = true});
        await collection.AddAsync(new { Name = "Second false entry", Include = false });

        var query = collection.WhereEqualTo("Include", true);
        var querySnapshot = await query.GetSnapshotAsync();
        foreach (var document in querySnapshot)
        {
            Console.WriteLine(document.GetValue<string>("Name"));
        }
    }
}

Output:

First true entry
Second true entry

Could you try this code locally, and see whether it works for you? If this works, please could you try amending it to query your existing collection?

[skjagini]

Could you try this code locally, and see whether it works for you? If _this_ works, please could you try amending it to query your existing collection?

Hi John I tried your code by creating a new Console app and it worked with Cloud Firestore (not emulator, as I have credential file already), it created a new Collection with guid and got results properly.

I just changed the code to point to the collection I have and with boolean flag and it times out with same exception I posted for. I have around 200K documents, I am expecting that shouldn't be any concern, but can it be?

       var db = FirestoreDb.Create("projectid");

        var collection = db.Collection("CollectionName");
        var query = collection.WhereEqualTo("SomeFlag", true);
        var querySnapshot = await query.GetSnapshotAsync();
        foreach (var document in querySnapshot)
        {
            Console.WriteLine(document.GetValue<string>("Name"));
        }

I tried querying for string type and it works on the same collection.

[jskeet]

Okay, that's good to know, thank you. I shall have to ask the Firestore team about that.

[jskeet]

One thing to clarify - how many of those 200,000 documents would match the filter? I'm trying to work out whether this is a matter of "it takes a long time to get back a snapshot for a huge number of documents" or whether it's really about the filtering itself. I'll try to reproduce tomorrow with 200k documents - if I know how many of those should match, that would be great.

[skjagini]

99.9% of the documents have the flag.

Yeap, its must be timing out as there are lot of documents that match the filter. When I tried to find a document which has null value (for example) the query didn't time out as the document is in the minority of the collection.

[jskeet]

Right. Out of interest, do you see the same timeout if you just get a snapshot of the collection, unfiltered? I honestly don't know whether you should expect it to work.

[skjagini]

 var collection = db.Collection("CollectionName");
 var querySnapshot = await collection.GetSnapshotAsync();

The above does fail.

What else should I do if I want to fetch documents in paginated manner, skip some and fetch some, I am interested in no more than 100 documents at a time based on the where clause

[jskeet]

I'll have to look at what the options are - I'm not deeply familiar with using the Firestore API (as I'm not a specialist in specific APIs, just the client libraries). I'll have a look tomorrow. I believe you'll want to specify a limit on one call, then specify a "start at..." cursor for the next query.

[jskeet]

Note: if your app is something new to help with the impact of the current health emergency, let me know and I'll try to look tonight. Otherwise, it'll be tomorrow (UK time).

[skjagini]

Note: if your app is something new to help with the impact of the current health emergency, let me know and I'll try to look tonight. Otherwise, it'll be tomorrow (UK time).

Not related to emergency

[skjagini]

I'll have to look at what the options are - I'm not deeply familiar with using the Firestore API (as I'm not a specialist in specific APIs, just the client libraries). I'll have a look tomorrow. I believe you'll want to specify a limit on one call, then specify a "start at..." cursor for the next query.

Thank you, the following worked, do you see any issues

       var db = FirestoreDb.Create("projectid");

        var collection = db.Collection("CollectionName").Limit(10);
        var query = collection.WhereEqualTo("SomeFlag", true);
        var querySnapshot = await query.Offset(30).GetSnapshotAsync();
        foreach (var document in querySnapshot)
        {
            Console.WriteLine(document.GetValue<string>("Name"));
        }

[jskeet]

I suspect using Offset like that will become very slow when you get to much later "pages" of the results. I'll write up a complete test of this later on.

[jskeet]

(Removed the bug label as I suspect there's no bug here, just a matter of the best API usage. Currently populating a large collection...)

[jskeet]

Okay, I've now had time to put together a complete program, which is shown below. It shows three ways of fetching the query results:

• Using the StreamAsync method. If you're using C# 8 and can depend on the 2.0.0-beta01 or 2.0.0-beta02 versions, this is the simplest option to use (with caveats)
• Executing queries multiple times, using a DocumentSnapshot as a cursor
• Executing queries multiple times, using an offset

Results:

• StreamAsync worked well to start with, fetching 210K records in just over a minute - but it then timed out. I'm not entirely sure why; I suspect something somewhere is asserting a one minute timeout, but I don't know what.
• Querying with cursors: this worked very well, fetching nearly as fast as streaming, but completing - it counted 910183 items in 330s
• Querying with offsets: this slowed down really quickly. I stopped it after a while - after five minutes it had only counted 60,000 items, and was getting slower and slower

Increasing the limit (to perform fewer queries) would no doubt help make the offset approach work better, but using cursors is clearly better. If your code wouldn't make it easy to use DocumentSnapshot, you can create a cursor in other ways, but it'll take more work. (You'll need to specify that you're ordering by document ID, then specify the document ID as the cursor.)

I'm going to close this issue now as I believe I've addressed everything - please add a comment if you need more help though.

using Google.Cloud.Firestore;
using System;
using System.Diagnostics;
using System.Linq;
using System.Threading.Tasks;

class Program
{
    static async Task Main(string[] args)
    {
        var db = FirestoreDb.Create(args[0]);

        // Note: comment this out after the first run! 
        // It actually failed for me due to too much contention, but only after it had written about 900K documents.
        var collection = db.Collection("Issue4561-attempt2");

        await PopulateCollectionAsync(collection);
        await CountViaStreaming(collection);
        await CountViaCursors(collection);
        await CountViaOffsets(collection);
    }

    static async Task CountViaStreaming(CollectionReference collection)
    {
        Console.WriteLine("Counting using query streaming");
        var stopwatch = Stopwatch.StartNew();
        int count = 0;
        var stream = collection.WhereEqualTo("Include", true).StreamAsync();
        await foreach (var item in stream)
        {
            count++;
            MaybeLogCount(count);
        }
        stopwatch.Stop();
        Console.WriteLine($"Counted {count} items in {(int) stopwatch.Elapsed.TotalSeconds}s");
    }

    static async Task CountViaCursors(CollectionReference collection)
    {
        Console.WriteLine("Counting using cursors");
        int limit = 1000;
        var query = collection.WhereEqualTo("Include", true).Limit(limit);
        var stopwatch = Stopwatch.StartNew();
        int count = 0;

        DocumentSnapshot lastDocument = null;
        while (true)
        {
            var queryWithCursor = lastDocument is null ? query : query.StartAfter(lastDocument);
            var querySnapshot = await queryWithCursor.GetSnapshotAsync();
            foreach (var document in querySnapshot)
            {
                count++;
                MaybeLogCount(count);
                lastDocument = document;
            }
            if (querySnapshot.Count != limit)
            {
                break;
            }
        }
        stopwatch.Stop();
        Console.WriteLine($"Counted {count} items in {(int) stopwatch.Elapsed.TotalSeconds}s");
    }

    static async Task CountViaOffsets(CollectionReference collection)
    {
        Console.WriteLine("Counting using offsets");
        int limit = 1000;
        var query = collection.WhereEqualTo("Include", true).Limit(limit);
        var stopwatch = Stopwatch.StartNew();
        int count = 0;

        while (true)
        {
            var queryWithOffset = query.Offset(count);
            var querySnapshot = await queryWithOffset.GetSnapshotAsync();
            foreach (var document in querySnapshot)
            {
                count++;
                MaybeLogCount(count);
            }
            if (querySnapshot.Count != limit)
            {
                break;
            }
        }
        stopwatch.Stop();
        Console.WriteLine($"Counted {count} items in {(int) stopwatch.Elapsed.TotalSeconds}s");
    }

    static void MaybeLogCount(int count)
    {
        if (count % 10000 == 0)
        {
            Console.WriteLine($"{DateTime.UtcNow:HH:mm:ss} Fetched {count} items");
        }
    }

    static async Task PopulateCollectionAsync(CollectionReference collection)
    {
        // Execute 100 parallel threads, each inserting 10,000 items in batches of 100.
        var tasks = Enumerable.Range(0, 100)
            .Select(chunk => InsertChunkAsync(chunk))
            .ToList();

        await Task.WhenAll(tasks);

        async Task InsertChunkAsync(int chunk)
        {
            for (int batch = 0; batch < 100; batch++)
            {
                var writeBatch = collection.Database.StartBatch();
                for (int i = 0; i < 100; i++)
                {
                    var id = i + (batch * 100) + (chunk * 10_000);
                    bool included = id % 1000 != 0;
                    var item = new { Name = $"Entry {i}", ItemId = id, Include = included };
                    writeBatch.Create(collection.Document(), item);
                }
                await writeBatch.CommitAsync();
                Console.WriteLine($"Completed batch {chunk} / {batch}");
            }
        }
    }
}

[skjagini]

Thank you Jon for all the samples, very helpful, here are my thoughts

Tried CountViaOffsets and when the offset is huge, it timesout eventually.
CountViaStreaming: Looks very clean, but my concern is Firestore charges based on read operations, and as we can't offset directly, may get charged for all
CountViaCursors: Seems to be better option.

[DiegoECQ]

Guys,

i have a collection of 350.000 documents, i want to update 1 value of all documents and i'm tryint this to get all collection:
ApiFuture<QuerySnapshot> future = db.collection("customers").get(); List<QueryDocumentSnapshot> documents = future.get().getDocuments();
But, i have this error:
Caused by: java.util.concurrent.ExecutionException: com.google.api.gax.rpc.UnavailableException: io.grpc.StatusRuntimeException: UNAVAILABLE: The datastore operation timed out, or the data was temporarily unavailable.

Can you help me please

[jskeet]

@DiegoECQ: Right, so you'd need to use one of the techniques shown above. Pulling all 350K documents into memory in one query as you're currently trying to do simply isn't going to work.