200.5 - IdentifyLayersAsync - cancellation token not working and application freeze

[BjørnarSundsbø1]

Using ArcGIS Maps SDK for .NET 200.5, I am having some issues with IdentifyLayersAsync and cancellation token.

I am working on a map with a few clustered feature layers, and at certain map scales the Identify operation will be very slow when identifying the clusters. This is particularly true when having just navigated the map before performing the identify operation, while DrawState is InProgress.

It appears that performing multiple sequential calls to this method are queued if user taps the view several times in a row and the previous Identify has not been completed. What happens next is that first call is blocking the next call, and the time the user has to wait increases for every new identify request.

I've used CancellationTokenSource and pass the token to the Identify method. When cancelling the token, the IdentifyLayersAsync does not appear to actually be cancelled until the last request has finished.

Looking at the source for GeoView, the request _coreReference.IdentifyLayers method does not use the cancellation token, but  uses CoreTaskExtensions.AsTask to try to perform some cancellation that seems ineffective. As far as I can tell, Cancel registration does not work, is not called or doesn't end the native call.

I can see that AsTask is used in multiple locations of the API, and if it doesn't do the trick here, I'm guessing the same might be the case in other locations (assuming I've not missed something critical in my own code).

    private async Task<IReadOnlyList<IdentifyLayerResult>> IdentifyLayersInternal(
      Point screenPoint,
      double tolerance,
      bool returnPopupsOnly,
      long maximumResultsPerLayer,
      CancellationToken cancellationToken)
    {
      return (IReadOnlyList<IdentifyLayerResult>) new IdentifyLayerResultList(await this._coreReference.IdentifyLayers(this.TransformToDrawSurface(screenPoint), tolerance, returnPopupsOnly, (int) maximumResultsPerLayer).AsTask<CoreArray>(cancellationToken).ConfigureAwait(false));
    }

This is the code to reproduce.

        private int _identifyCounter;
        private async void MapView_MapViewTapped(object sender, GeoViewInputEventArgs e)
        {
            var currentCounter = Interlocked.Increment(ref _identifyCounter);

            if (_cancellationTokenSource != null)
            {
                await _cancellationTokenSource.CancelAsync();
                _cancellationTokenSource.Dispose();
                _cancellationTokenSource = null;
                Trace.WriteLine($"Previous token CancelAsync", $"Tapped {currentCounter}");
            }

            CancellationTokenSource source = _cancellationTokenSource = new CancellationTokenSource();

            var identifyWatch = Stopwatch.StartNew();
            try
            {
                Trace.WriteLine("Start identify", $"OnIdentify {currentCounter}");
                // Used when mapscale is less than 1 : 100.000
                var maxResultPerLayer = 12; 
                var tolerance = 15;
                await MapView.IdentifyGraphicsOverlaysAsync(e.Position, tolerance, false, maxResultPerLayer);
                await MapView.IdentifyLayersAsync(e.Position, tolerance, returnPopupsOnly: true, maxResultPerLayer, source.Token);
                identifyWatch.Stop();
            }
            catch (OperationCanceledException)
            {
                identifyWatch.Stop();
                Trace.WriteLine($"OperationCanceledException after {identifyWatch.Elapsed}", $"Tapped {currentCounter}");
            }
            catch (Exception ex)
            {
                Trace.WriteLine(ex);
            }
            finally
            {
                if(!source.IsCancellationRequested)
                {
                    Trace.WriteLine($"Finished after {identifyWatch.Elapsed}", $"Tapped {currentCounter}");
                }

                Interlocked.Decrement(ref _identifyCounter);
                _cancellationTokenSource?.Dispose();
                _cancellationTokenSource = null;
                source?.Dispose();
            }
        }

The trace I get here is as follows:

Tapped 1: Finished after 00:00:00.1374115
OnIdentify 1: Start identify
Tapped 2: Previous token CancelAsync
OnIdentify 2: Start identify
Tapped 3: Previous token CancelAsync
OnIdentify 3: Start identify
Tapped 4: Previous token CancelAsync
OnIdentify 4: Start identify
Tapped 5: Previous token CancelAsync
OnIdentify 5: Start identify
Tapped 6: Previous token CancelAsync
OnIdentify 6: Start identify
Tapped 7: Previous token CancelAsync
OnIdentify 7: Start identify
Tapped 8: Previous token CancelAsync
OnIdentify 8: Start identify
Tapped 9: Previous token CancelAsync
OnIdentify 9: Start identify
Tapped 10: Previous token CancelAsync
OnIdentify 10: Start identify
Tapped 11: Previous token CancelAsync
OnIdentify 11: Start identify
Tapped 12: Previous token CancelAsync
OnIdentify 12: Start identify
Tapped 13: Previous token CancelAsync
OnIdentify 13: Start identify
Tapped 13: Finished after 00:00:12.8716381
Tapped 10: OperationCanceledException after 00:00:13.9292636
Tapped 11: OperationCanceledException after 00:00:13.6609924
Tapped 8: OperationCanceledException after 00:00:15.0679175
Tapped 2: OperationCanceledException after 00:00:18.1325766
Tapped 3: OperationCanceledException after 00:00:17.7673405
Tapped 9: OperationCanceledException after 00:00:14.6338782
Tapped 6: OperationCanceledException after 00:00:16.2799953
Tapped 12: OperationCanceledException after 00:00:13.5238723
Tapped 5: OperationCanceledException after 00:00:16.7167265
Tapped 4: OperationCanceledException after 00:00:17.4615539
Tapped 1: OperationCanceledException after 00:00:18.7209363
Tapped 7: OperationCanceledException after 00:00:15.8465043

If the cancellation worked properly, I would have expected the OperationCancelledException before each Start identify log statement, and the elapsed to not be insane 🙂

I will update the task with a sample webmap when my team has been able to extract the necessary data for public publishing, but hopefully there is enough information to go on here

Is there something that I am missing, or is there a bug going on here?

[BjørnarSundsbø1]

I've attached animation of the output of the trace. On bad tests this can accumulate up to an elapsed time of over a minute if I'm impatient enough to be aggressive with clicking

 

[BjørnarSundsbø1]

I can reproduce the issue in this application. Zoom in/out, click clusters/features with high frequency, and the "Concurrent identify count" on the screen will increase and the trace can be seen in the output window

This application can also reproduce an issue where the whole application deadlocks and remains frozen, unresponsive to any input, task manager termination or the debugger being able to pause to see where the freeze occurs.

In a different scenario where I had identify on mouse move, the above issue would occur when IdentifyLayer/IdentifyOverlay happens when DrawState was InProgress. For the tooltip I could disable the feature if map has not finished drawing.

For identify through click would confuse the user with "nothing happening", but is of course a work-around to keep the application from crashing/freezing.

The sample can also replicate a binding error in the Toolkit like this:

System.Windows.Data Error: 1 : Cannot create default converter to perform 'one-way' conversions between types 'Esri.ArcGISRuntime.Mapping.Popups.FieldsPopupElement' and 'Esri.ArcGISRuntime.Mapping.Popups.AttachmentsPopupElement'. Consider using Converter property of Binding.
System.Windows.Data Error: 5 : Value produced by BindingExpression is not valid for target property. FieldsPopupElement:'Esri.ArcGISRuntime.Mapping.Popups.FieldsPopupElement' BindingExpression:Path=; DataItem='FieldsPopupElement' (HashCode=35307962); target element is 'FieldsPopupElementView' (Name=''); target property is 'Element' (type 'AttachmentsPopupElement')

As a side note, I can occasionally get an NullReferenceException with the CancellationTokenSource if I'm extremely aggressive, though I don't think that is related to the root issue, though I'd be open to be proved wrong

[QuintenKent]

Hi, thank you for the detailed notes and sample app.

I think the behavior you've identified here

I am working on a map with a few clustered feature layers, and at certain map scales the Identify operation will be very slow when identifying the clusters.

Is unfortunately an expected outcome for these reasons:

• As you observed, this behavior is tied to draw status. In our current implementation, identify tasks can be added to an internal queue, but are only processed once draw status reaches the Completed state.
• When the previous identify task is canceled via await _cancellationTokenSource.CancelAsync(), the canceled await MapView.IdentifyLayersAsync task continues to block until we've reached draw complete and process identify tasks.

So, the behavior observed is caused by the length of time required to reach draw complete, and not by the actual number of identify requests made.

It looks like the output you've shared backs this up too:

• You can see that there are 13 different identify operations that get started
• Based on output, you can see that each thread is blocking on the call to await MapView.IdentifyLayersAsync
• Then, once we reach draw complete, the most recent identify task succeeds (Tapped 13: Finished after 00:00:12.8716381) and all previous tasks report an OperationCanceledException

We'll look and see if there's a way that a canceled task can return sooner from the call to await.

Also, for the binding errors you've identified, are you able to update the version of your toolkit from 200.5 to 200.6? I don't see this warning when using version 200.6 of the toolkit.

[BjørnarSundsbø1]

Hi @QuintenKent 

Thank you for getting back to me. I've extended the sample a little bit.

• New button for adding graphics to graphics overlays so graphics can be identified* 
• Press Control key to identify on mouse move
• Updated to 200.6

New and old discoveries (see screenshot)

• when using control and mouse move, the drawstate flips between InProgress and Completed continiously
• Sometimes when using control + mouse move to identify, the queue keeps increasing and is never processed
• Sometimes the application crashes. I've seen that in our application in particular when identifying graphics while DrawState is InProgress. Most easily reproduced when zooming in to get map InProgress, and then keep control key down while moving the cursor to on and off a diamond symbol.
• I see AsTask is used in many different areas of the application, such as Locators and FeatureService. If the cancellation/blocking can be fixed for identify, I also imagine we can have benefits in other areas of the application when it comes to cancellation.

Updating both toolkit and SDK to 200.6 removes the binding error

[QuintenKent]

Hi @BjørnarSundsbø1, thank you for the update! Glad that moving to 200.6 fixed the binding errors you were seeing.

For some of your other points:

• Sometimes when using control + mouse move to identify, the queue keeps increasing and is never processed

I was able to observe this too when running the provided sample app.

I think this may be down to how the lifetime of the _cancellationTokenSource member is managed. In particular, if the MapView.IdentifyLayersAsync operation is canceled, then in the finally block we still call _cancellationTokenSource?.Dispose();. I believe this has the effect of calling Dispose on the cancellation token associated with the active, uncanceled identify Task.

If I apply the diff below to your sample app then I no longer see this problem.

diff --git a/MainWindow.xaml.cs b/MainWindow.xaml.cs
index a510c9c..63a29aa 100644
--- a/MainWindow.xaml.cs
+++ b/MainWindow.xaml.cs
@@ -113,13 +113,12 @@ public partial class MainWindow : Window, INotifyPropertyChanged
             if (!source.IsCancellationRequested)
             {
                 Trace.WriteLine($"Finished after {identifyWatch.Elapsed}", $"Tapped {currentCounter}");
+                source.Dispose();
+                _cancellationTokenSource = null;
             }

             Interlocked.Decrement(ref _identifyCounter);
             OnPropertyChanged(nameof(IdentifyCounter));
-            _cancellationTokenSource?.Dispose();
-            _cancellationTokenSource = null;
-            source.Dispose();
         }
     }

Also, I think there may be a potential bug hidden in the call to await _cancellationTokenSource.CancelAsync();. By using the async cancel method, it makes it possible for multiple identify operations to pile up if CancelAsync takes a while to return. I recommend replacing this with the non-async cancel method (see the diff below).

diff --git a/MainWindow.xaml.cs b/MainWindow.xaml.cs
index a510c9c..8d5e552 100644
--- a/MainWindow.xaml.cs
+++ b/MainWindow.xaml.cs
@@ -77,7 +77,7 @@ public partial class MainWindow : Window, INotifyPropertyChanged
         OnPropertyChanged(nameof(IdentifyCounter));
         if (_cancellationTokenSource != null)
         {
-            await _cancellationTokenSource.CancelAsync();
+            _cancellationTokenSource.Cancel();
             _cancellationTokenSource?.Dispose();
             _cancellationTokenSource = null;
             Trace.WriteLine($"Previous token CancelAsync", $"Tapped {currentCounter}");

• I see AsTask is used in many different areas of the application, such as Locators and FeatureService. If the cancellation/blocking can be fixed for identify, I also imagine we can have benefits in other areas of the application when it comes to cancellation.

I do want to clarify that in this case, cancellation is being honored for identify operations in the Maps SDK. Due to our implementation, this cancellation is only observed (via an OperationCanceledException) after the map view reaches draw complete--which is not the intuitive expectation, and can be improved on our end.

• Sometimes the application crashes. I've seen that in our application in particular when identifying graphics while DrawState is InProgress. Most easily reproduced when zooming in to get map InProgress, and then keep control key down while moving the cursor to on and off a diamond symbol.

Finally, for the crash, would you be able to re-test with the changes to cancellation token source mentioned previously? I would be curious if they are related.

Thanks!

[BjørnarSundsbø1]

I've tried the cancellation token changes which seems to have some effect on the unprocessed queue.

Related to the crash, it occurs from time to time, but with two symptoms. The way to reproduce is to zoom the map so DrawState is InProgress and then use Control + mouse move to build the queue.

The symptoms:

• Queue keeps building, and then the map freezes for a while but resumes
• Queue keeps building, and while processing after the freeze, the application crashes

It might beneficial to create a sample for the Tutorials section of the training materials for identify with cancellation token for others in the future. I've seen some samples where mouse move is used for map tips. Our real application has/had layers with crazy amount of data where it would take over a minute before the task was cancelled with only a few queued identify operations. The webmap was the minimum to reproduce the issue.