Bug 61047 - C++ Native callback breaks app
Summary: C++ Native callback breaks app
Status: NEW
Alias: None
Product: Android
Classification: Xamarin
Component: Mono runtime / AOT Compiler ()
Version: 8.0 (15.4)
Hardware: Other Other
: --- normal
Target Milestone: ---
Assignee: Marek Habersack
URL:
Depends on:
Blocks:
 
Reported: 2017-12-08 13:54 UTC by manuel.eugster
Modified: 2017-12-12 06:52 UTC (History)
1 user (show)

Tags:
Is this bug a regression?: ---
Last known good build:


Attachments
Xamarin Android Sample Callback Crash App (1.78 MB, application/x-zip-compressed)
2017-12-08 13:54 UTC, manuel.eugster
Details


Notice (2018-05-24): bugzilla.xamarin.com is now in read-only mode.

Please join us on Visual Studio Developer Community and in the Xamarin and Mono organizations on GitHub to continue tracking issues. Bugzilla will remain available for reference in read-only mode. We will continue to work on open Bugzilla bugs, copy them to the new locations as needed for follow-up, and add the new items under Related Links.

Our sincere thanks to everyone who has contributed on this bug tracker over the years. Thanks also for your understanding as we make these adjustments and improvements for the future.


Please create a new report for Bug 61047 on Developer Community or GitHub if you have new information to add and do not yet see a matching new report.

If the latest results still closely match this report, you can use the original description:

  • Export the original title and description: Developer Community HTML or GitHub Markdown
  • Copy the title and description into the new report. Adjust them to be up-to-date if needed.
  • Add your new information.

In special cases on GitHub you might also want the comments: GitHub Markdown with public comments

Related Links:
Status:
NEW

Description manuel.eugster 2017-12-08 13:54:08 UTC
Created attachment 25950 [details]
Xamarin Android Sample Callback Crash App

We use native c++ code for image calculation in our xamarin android app. We pass the image data to the c++ code and get a callback once the calculation is done. 
We observed that callbacks from a native c++ library can crash / freeze the xamarin android applicaton.
The crash occurs more often when more memory is used.

We created a simple sample app with which the crash is reproduceable (Is attached). 
The c++ code has just one methode : TestCallback(void(*callback)(), uint32_t ms)

The method waits for the given time in ms and in the half time the callback is called.
The app has only one button which calls the method a few times.
If we allocate memory in order that the gc has to run, the app crashes.


All tests performed with Xamarin: 4.2.2.11 Xamarin.Android: 7.0.2.42 and Xamarin: 4.7.10.38 Xamarin.Android: 8.0.2.1

The following c# code within an Android Activity
/// <summary>
/// Button click event handler
/// </summary>
/// <param name="sender"></param>
/// <param name="eventArgs"></param>
private void BtnStartButtonOnClick(object sender, EventArgs eventArgs)
{
    Task.Factory.StartNew(RunCallbacks);
}
 
/// <summary>
/// Call the native (c++) TestCallback function.
/// We will be called back in the OnCallback method
/// </summary>
private void RunCallbacks()
{
    for (int i = 0; i < IterationCount; ++i)
    {
        try
        {
            Log.Warn("CallbackBugApp", "Allocate 1MB");
            _buffer = new byte[1024 * 1024];
            _callback.TestCallback(OnCallback, 40);
        }
        catch (Exception ex)
        {
            Log.Warn("CallbackBugApp", "Error calling TestCallback " + ex.Message);
        }
    }
}
 
private void OnCallback()
{
    Log.Warn("CallbackBugApp", "Callback from native");
    RunOnUiThread(() => _tvCount.Text = (_callbackNo++).ToString());
}

 

With the c++ function
#include "TestCallback.h"
 
#include <iostream>
#include <future>
 
void TestCallback(void(*callback)(), uint32_t ms)
{
    std::cout << "TestCallback(): begin" << std::endl;
 
    auto a = std::async(std::launch::async, [&] {
        std::this_thread::sleep_for(std::chrono::milliseconds(ms/2));
 
        std::cout << "TestCallback(): call callback() : begin" << std::endl;
        callback();
        std::cout << "TestCallback(): call callback() : end" << std::endl;
    });
    std::this_thread::sleep_for(std::chrono::milliseconds(ms));
 
    std::cout << "TestCallback(): end" << std::endl;
}

 

Causes the App to freeze. Note that if we comment out the buffer allocation (_buffer = new byte[1024 * 1024]) or the TestCallback call (_callback.TestCallback(OnCallback, 40)) the App does not freeze.   

We see, that when the app freezes, the Garbage Collector has never run
Thread started:  #17
TestCallback(): call callback() : end
12-06 17:40:45.941 W/CallbackBugApp(27540): Callback from native
Thread finished:  #17
12-06 17:40:45.952 W/CallbackBugApp(27540): Allocate 1MB
TestCallback(): begin
TestCallback(): call callback() : begin
TestCallback(): end
Thread started:  #18
12-06 17:40:45.999 W/CallbackBugApp(27540): Callback from native
TestCallback(): call callback() : end
Thread finished:  #18
12-06 17:40:46.009 W/CallbackBugApp(27540): Allocate 1MB
TestCallback(): begin
TestCallback(): call callback() : begin
TestCallback(): end
Thread started:  #19
TestCallback(): call callback() : end
12-06 17:40:46.058 W/CallbackBugApp(27540): Callback from native
Thread finished:  #19
12-06 17:40:46.072 W/CallbackBugApp(27540): Allocate 1MB
TestCallback(): begin
The thread 'Unknown' (0x10) has exited with code 0 (0x0).
The thread 'Unknown' (0x11) has exited with code 0 (0x0).
The thread 'Unknown' (0x12) has exited with code 0 (0x0).
The thread 'Unknown' (0x13) has exited with code 0 (0x0).
TestCallback(): call callback() : begin
TestCallback(): end
Thread started:  #20
TestCallback(): call callback() : end
12-06 17:40:46.133 W/CallbackBugApp(27540): Callback from native
Thread finished:  #20
12-06 17:40:46.143 W/CallbackBugApp(27540): Allocate 1MB
TestCallback(): begin
TestCallback(): call callback() : begin
TestCallback(): end
The thread 'Unknown' (0x14) has exited with code 0 (0x0).

 

...while when the TestCallback call is commented out the GC runs in a regular base
12-06 17:43:49.197 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.197 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.199 I/art     (27699): Starting a blocking GC Explicit
12-06 17:43:49.211 I/art     (27699): Explicit concurrent mark sweep GC freed 35(1480B) AllocSpace objects, 0(0B) LOS objects, 40% free, 2MB/4MB, paused 172us total 11.895ms
12-06 17:43:49.211 D/Mono    (27699): GC_TAR_BRIDGE bridges 1 objects 2 colors 1 ignored 0 sccs 1 xref 0 cache 0/0 setup 0.08ms tarjan 0.01ms scc-setup 0.00ms gather-xref 0.00ms xref-setup 0.00ms cleanup 0.04ms
12-06 17:43:49.211 D/Mono    (27699): GC_BRIDGE: Complete, was running for 12.48ms
12-06 17:43:49.211 D/Mono    (27699): GC_MAJOR: (LOS overflow) time 1.32ms, stw 1.55ms los size: 2052K in use: 1032K
12-06 17:43:49.211 D/Mono    (27699): GC_MAJOR_SWEEP: major size: 784K in use: 47K
12-06 17:43:49.212 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.212 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.212 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.212 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.212 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.212 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.212 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.212 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.212 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.212 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.212 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.212 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.213 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.213 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.213 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.213 W/CallbackBugApp(27699): Allocate 1MB
12-06 17:43:49.215 I/art     (27699): Starting a blocking GC Explicit
12-06 17:43:49.228 I/art     (27699): Explicit concurrent mark sweep GC freed 35(1480B) AllocSpace objects, 0(0B) LOS objects, 40% free, 2MB/4MB, paused 187us total 11.934ms
12-06 17:43:49.228 D/Mono    (27699): GC_TAR_BRIDGE bridges 1 objects 2 colors 1 ignored 0 sccs 1 xref 0 cache 0/0 setup 0.11ms tarjan 0.01ms scc-setup 0.03ms gather-xref 0.00ms xref-setup 0.00ms cleanup 0.04ms
12-06 17:43:49.228 D/Mono    (27699): GC_BRIDGE: Complete, was running for 12.53ms
12-06 17:43:49.228 D/Mono    (27699): GC_MAJOR: (LOS overflow) time 1.53ms, stw 2.45ms los size: 2052K in use: 1032K
12-06 17:43:49.228 D/Mono    (27699): GC_MAJOR_SWEEP: major size: 784K in use: 47K
12-06 17:43:49.228 W/CallbackBugApp(27699): Allocate 1MB


Let me know if you need further information.