Crash on exit if I unbind

classic Classic list List threaded Threaded
26 messages Options
12
Reply | Threaded
Open this post in threaded view
|

Crash on exit if I unbind

Hugo
Im using Cling 1.0.5 and I get a crash on quit like 90% of the time I quit my application. If I dont unbind from Cling then the crash does not happen. All the rest works fine. I have no idea where is the problem so any help is appreciated. Relevant code and logs:

Code:

        @Override
        public void onDestroy () {
               
                unbindFromCling();

        }

        private void bindToCling () {
               
                if ( (feederState == FeederState.BINDING) || (feederState == FeederState.CONNECTED) )
                        return;
               
                //Cling debug levels
                //org.teleal.common.logging.LoggingUtil.resetRootHandler(new FixedAndroidHandler());
                //java.util.logging.Logger.getLogger("org.teleal.cling").setLevel(Level.FINE);
               
                getApplicationContext().bindService( new Intent(this, AndroidUpnpServiceImpl.class),
                clingServiceConnection,
                Context.BIND_AUTO_CREATE);

                feederState = FeederState.BINDING;
               
        }
       
        private void unbindFromCling () {
               
                Log.d(LOG_TAG, "unbindFromCling, FeederState: " + feederState.toString());
               
                if (feederState == FeederState.DISCONNECTED)
                        return;
               
                synchronized (upnpServiceSync) {
                        if (upnpService != null) {
                                upnpService.getRegistry().removeListener(registryListener);
                                upnpService = null;
                        }
                }
                registryListener = null;
               
               
                getApplicationContext().unbindService(clingServiceConnection);
                feederState = FeederState.DISCONNECTED;
               
        }

Log (from the relevant point):

01-29 12:27:24.830: I/UpnpServiceImpl(19433): >>> Shutting down UPnP service...
01-29 12:27:24.850: D/AndroidRuntime(19433): Shutting down VM
01-29 12:27:24.850: W/dalvikvm(19433): threadid=1: thread exiting with uncaught exception (group=0x40a13300)
01-29 12:27:24.901: E/AndroidRuntime(19433): FATAL EXCEPTION: main
01-29 12:27:24.901: E/AndroidRuntime(19433): java.lang.RuntimeException: Unable to stop service org.teleal.cling.android.AndroidUpnpServiceImpl@412ca010: android.os.NetworkOnMainThreadException
01-29 12:27:24.901: E/AndroidRuntime(19433): at android.app.ActivityThread.handleStopService(ActivityThread.java:2537)
01-29 12:27:24.901: E/AndroidRuntime(19433): at android.app.ActivityThread.access$2000(ActivityThread.java:130)
01-29 12:27:24.901: E/AndroidRuntime(19433): at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1297)
01-29 12:27:24.901: E/AndroidRuntime(19433): at android.os.Handler.dispatchMessage(Handler.java:99)
01-29 12:27:24.901: E/AndroidRuntime(19433): at android.os.Looper.loop(Looper.java:137)
01-29 12:27:24.901: E/AndroidRuntime(19433): at android.app.ActivityThread.main(ActivityThread.java:4745)
01-29 12:27:24.901: E/AndroidRuntime(19433): at java.lang.reflect.Method.invokeNative(Native Method)
01-29 12:27:24.901: E/AndroidRuntime(19433): at java.lang.reflect.Method.invoke(Method.java:511)
01-29 12:27:24.901: E/AndroidRuntime(19433): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:786)
01-29 12:27:24.901: E/AndroidRuntime(19433): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:553)
01-29 12:27:24.901: E/AndroidRuntime(19433): at dalvik.system.NativeStart.main(Native Method)
01-29 12:27:24.901: E/AndroidRuntime(19433): Caused by: android.os.NetworkOnMainThreadException
01-29 12:27:24.901: E/AndroidRuntime(19433): at android.os.StrictMode$AndroidBlockGuardPolicy.onNetwork(StrictMode.java:1117)
01-29 12:27:24.901: E/AndroidRuntime(19433): at libcore.io.BlockGuardOs.recvfrom(BlockGuardOs.java:163)
01-29 12:27:24.901: E/AndroidRuntime(19433): at libcore.io.IoBridge.recvfrom(IoBridge.java:513)
01-29 12:27:24.901: E/AndroidRuntime(19433): at java.net.PlainSocketImpl.read(PlainSocketImpl.java:488)
01-29 12:27:24.901: E/AndroidRuntime(19433): at java.net.PlainSocketImpl.access$000(PlainSocketImpl.java:46)
01-29 12:27:24.901: E/AndroidRuntime(19433): at java.net.PlainSocketImpl$PlainSocketInputStream.read(PlainSocketImpl.java:240)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:103)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:191)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.impl.conn.DefaultResponseParser.parseHead(DefaultResponseParser.java:82)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:174)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:180)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:235)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.impl.conn.AbstractClientConnAdapter.receiveResponseHeader(AbstractClientConnAdapter.java:259)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:279)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:121)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:428)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:555)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:653)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:627)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:616)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.teleal.cling.transport.impl.apache.StreamClientImpl.sendRequest(StreamClientImpl.java:144)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.teleal.cling.transport.RouterImpl.send(RouterImpl.java:282)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.teleal.cling.transport.SwitchableRouterImpl.send(SwitchableRouterImpl.java:190)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.teleal.cling.protocol.sync.SendingUnsubscribe.executeSync(SendingUnsubscribe.java:55)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.teleal.cling.protocol.SendingSync.execute(SendingSync.java:55)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.teleal.cling.protocol.SendingAsync.run(SendingAsync.java:44)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.teleal.cling.registry.RemoteItems.shutdown(RemoteItems.java:300)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.teleal.cling.registry.RegistryImpl.shutdown(RegistryImpl.java:372)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.teleal.cling.UpnpServiceImpl.shutdown(UpnpServiceImpl.java:129)
01-29 12:27:24.901: E/AndroidRuntime(19433): at org.teleal.cling.android.AndroidUpnpServiceImpl.onDestroy(AndroidUpnpServiceImpl.java:101)
01-29 12:27:24.901: E/AndroidRuntime(19433): at android.app.ActivityThread.handleStopService(ActivityThread.java:2520)
01-29 12:27:24.901: E/AndroidRuntime(19433): ... 10 more
01-29 12:27:24.961: D/UpnpMediaProviderFeeder(19433): Subscription ended for Content provider: urn:upnp-org:serviceId:ContentDirectory
01-29 12:27:24.991: D/dalvikvm(19433): GC_CONCURRENT freed 578K, 7% free 9651K/10375K, paused 53ms+7ms, total 125ms
01-29 12:27:24.991: D/dalvikvm(19433): WAIT_FOR_CONCURRENT_GC blocked 27ms
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

Robin
You have three options:

Option 1:
as documented here: http://developer.android.com/reference/android/os/NetworkOnMainThreadException.html

set the target api version in your manifest file to android 10


Option 2:
give the new cling 2.0 alpha a try


Option 3:
build your own cling and use an AsyncTask to gracefully shut down the cling service
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

Michael Pujos
In reply to this post by Hugo
On shutdown(), Cling may do network I/O in the Main Thread, which some versions of Android will complain, throwing NetworkOnMainThreadException

Two possible solutions:

- change Cling so it doesn't do network I/O in the MT on shutdown
- disable NetworkOnMainThreadException by changing Android StrictMode thread policy for just the call to shutdown(), or for the whole app execution.
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

Hugo
In reply to this post by Robin
Thanks all for the quick answers. I was banging my head to the wall trying to understand where I had fucked up.

Robin wrote
Option 2:
give the new cling 2.0 alpha a try
I was already thinking on taking a look at Cling 2.0, this might just push me. How much different is the API of cling 2.0 vs cling 1? Also how stable is it?

Also

build your own cling and use an AsyncTask to gracefully shut down the cling service
Anyone has code for this? It seems a bit weird that Cling 1 has been left like this.
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

Christian Bauer
Administrator
As there are many many more tests in 2.0 it's probably more "stable" than 1.0 already. The API is not final, more changes are coming.

Btw, don't expect any official updates on 1.0, I won't even look at the code anymore. You are on your own with 1.0.

Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

Christian Bauer
Administrator
In reply to this post by Hugo
And Cling should never create any network traffic on the thread that calls UpnpService#shutdown(), that would be a bug. Other threads might still complete network communication before they are interrupted on shutdown, of course.

Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

Hugo
In reply to this post by Christian Bauer
Christian Bauer wrote
As there are many many more tests in 2.0 it's probably more "stable" than 1.0 already. The API is not final, more changes are coming.

Btw, don't expect any official updates on 1.0, I won't even look at the code anymore. You are on your own with 1.0.
I actually wanted to start developing on 2.0 directly, but I read that it needs target 15 minium which would leave 60+% of the Android phones right now out of the picture. Im sure there are technical reasons for those requirements, but its not practical at least for now.

And Cling should never create any network traffic on the thread that calls UpnpService#shutdown(), that would be a bug. Other threads might still complete network communication before they are interrupted on shutdown, of course.
This is the case. Ive tested unbinding after I disconnect from everything to drop subscriptions. If I unbind after the ended callback on the subscripton has been called, then Cling does not hang. Problem is this only works for my test, but since there are programs out there using Cling someone must have some solution.
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

Robin
in:
cling-1.0.5-source/core/src/main/java/org/teleal/cling/android/AndroidUpnpServiceImpl.java

at line 97

@Override
    public void onDestroy() {
        if (!ModelUtil.ANDROID_EMULATOR && isListeningForConnectivityChanges())
            unregisterReceiver(((AndroidWifiSwitchableRouter) upnpService.getRouter()).getBroadcastReceiver());
        upnpService.shutdown();
    }

replace with:

@Override
    public void onDestroy() {
        if (!ModelUtil.ANDROID_EMULATOR && isListeningForConnectivityChanges())
            unregisterReceiver(((AndroidWifiSwitchableRouter) upnpService.getRouter()).getBroadcastReceiver());
        new Shutdown().execute(upnpService);
    }

    private class Shutdown extends AsyncTask<UpnpService, Integer, Void> {

    @Override protected Void doInBackground(UpnpService... svcs) {
    UpnpService svc = svcs[0];
    if (null != svc) svc.shutdown();
    return null;
    }
    }
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

Christian Bauer
Administrator
In reply to this post by Hugo

On 29.01.2013, at 18:34, Hugo [via Mailinglists] <[hidden email]> wrote:

I actually wanted to start developing on 2.0 directly, but I read that it needs target 15 minium which would leave 60+% of the Android phones right now out of the picture. 

Actually it doesn't, the demos require 15. And even that might not be true, this is a secondary concern and we'll look at it in beta. Right now obviously nobody wants to spend time testing on different Android versions, so 15 it is.

Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

Hugo
Thanks all for the suggestions. Changing the ThreadPolicy on onDestroy worked, although Robin's solution is probably nicer.

Christian Bauer wrote
Actually it doesn't, the demos require 15. And even that might not be true, this is a secondary concern and we'll look at it in beta. Right now obviously nobody wants to spend time testing on different Android versions, so 15 it is.
Makes sense.
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

bergstr
In reply to this post by Christian Bauer
I just switched to 2.0, and am faithfully seeing NetworkOnMainThreadException from inside UpnpServiceImpl.shutdown(), as evidenced below:

FATAL EXCEPTION: main
java.lang.RuntimeException: Unable to stop service com.byterefinery.mediasteersman.upnp.SteersmanUpnpServiceImpl@41585940: android.os.NetworkOnMainThreadException
        at android.app.ActivityThread.handleStopService(ActivityThread.java:2703)
        at android.app.ActivityThread.access$2000(ActivityThread.java:141)
        at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1336)
        at android.os.Handler.dispatchMessage(Handler.java:99)
        at android.os.Looper.loop(Looper.java:137)
        at android.app.ActivityThread.main(ActivityThread.java:5039)
        at java.lang.reflect.Method.invokeNative(Native Method)
        at java.lang.reflect.Method.invoke(Method.java:511)
        at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:793)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:560)
        at dalvik.system.NativeStart.main(Native Method)
Caused by: android.os.NetworkOnMainThreadException
        at android.os.StrictMode$AndroidBlockGuardPolicy.onNetwork(StrictMode.java:1117)
        at libcore.io.BlockGuardOs.sendto(BlockGuardOs.java:175)
        at libcore.io.IoBridge.sendto(IoBridge.java:473)
        at java.net.PlainDatagramSocketImpl.send(PlainDatagramSocketImpl.java:182)
        at java.net.DatagramSocket.send(DatagramSocket.java:284)
        at org.fourthline.cling.transport.impl.DatagramIOImpl.send(DatagramIOImpl.java:151)
        at org.fourthline.cling.transport.impl.DatagramIOImpl.send(DatagramIOImpl.java:144)
        at org.fourthline.cling.transport.RouterImpl.send(RouterImpl.java:345)
        at org.fourthline.cling.transport.SwitchableRouterImpl.send(SwitchableRouterImpl.java:208)
        at org.fourthline.cling.protocol.async.SendingNotification.sendMessages(SendingNotification.java:109)
        at org.fourthline.cling.protocol.async.SendingNotification.execute(SendingNotification.java:83)
        at org.fourthline.cling.protocol.async.SendingNotificationByebye.execute(SendingNotificationByebye.java:49)
        at org.fourthline.cling.protocol.SendingAsync.run(SendingAsync.java:42)
        at org.fourthline.cling.registry.LocalItems.advertiseByebye(LocalItems.java:308)
        at org.fourthline.cling.registry.LocalItems.remove(LocalItems.java:181)
        at org.fourthline.cling.registry.LocalItems.removeAll(LocalItems.java:208)
        at org.fourthline.cling.registry.LocalItems.shutdown(LocalItems.java:282)
        at org.fourthline.cling.registry.RegistryImpl.shutdown(RegistryImpl.java:397)
        at org.fourthline.cling.UpnpServiceImpl.shutdown(UpnpServiceImpl.java:129)
        at com.byterefinery.mediasteersman.upnp.SteersmanUpnpServiceImpl.onDestroy(SteersmanUpnpServiceImpl.java:145)
        at android.app.ActivityThread.handleStopService(ActivityThread.java:2686)
        ... 10 more
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

bergstr
In reply to this post by Christian Bauer
unfortunately, when I move the shutdown to another thread, as I had in my code up until now (based on michael pujos's fork), and described in a previous post, I now see this:

FATAL EXCEPTION: AsyncTask #1
java.lang.RuntimeException: An error occured while executing doInBackground()
        at android.os.AsyncTask$3.done(AsyncTask.java:299)
        at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:352)
        at java.util.concurrent.FutureTask.setException(FutureTask.java:219)
        at java.util.concurrent.FutureTask.run(FutureTask.java:239)
        at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:230)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
        at java.lang.Thread.run(Thread.java:856)
Caused by: java.lang.IllegalArgumentException: Receiver not registered: org.fourthline.cling.android.AndroidSwitchableRouter$ConnectivityBroadcastReceiver@4164b6e8
        at android.app.LoadedApk.forgetReceiverDispatcher(LoadedApk.java:657)
        at android.app.ContextImpl.unregisterReceiver(ContextImpl.java:1339)
        at android.content.ContextWrapper.unregisterReceiver(ContextWrapper.java:445)
        at org.fourthline.cling.android.AndroidSwitchableRouter.shutdown(AndroidSwitchableRouter.java:82)
        at org.fourthline.cling.UpnpServiceImpl.shutdown(UpnpServiceImpl.java:130)
        at com.byterefinery.mediasteersman.upnp.SteersmanUpnpServiceImpl$Shutdown.doInBackground(SteersmanUpnpServiceImpl.java:145)
        at com.byterefinery.mediasteersman.upnp.SteersmanUpnpServiceImpl$Shutdown.doInBackground(SteersmanUpnpServiceImpl.java:1)
        at android.os.AsyncTask$2.call(AsyncTask.java:287)
        at java.util.concurrent.FutureTask.run(FutureTask.java:234)
        ... 4 more
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

bergstr
thinking about it, it seems quite obvious why this happens. According to the android (Context#getApplicationContext() javadoc) docs,
Consider for example how this interacts with registerReceiver(BroadcastReceiver, IntentFilter):

If used from an Activity context, the receiver is being registered within that activity. This means that you are expected to unregister before the activity is done being destroyed; in fact if you do not do so, the framework will clean up your leaked registration as it removes the activity and log an error. Thus, if you use the Activity context to register a receiver that is static (global to the process, not associated with an Activity instance) then that registration will be removed on you at whatever point the activity you used is destroyed.
this means the system will unregister the receiver, and there can be no guarantee that the thread hits before that. The only solution seems to be to move the code that does the Network I/O (below UpnpServiceImpl.shutdown) into a separate thread.
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

bergstr
Did this in UpnpServiceImpl, and the problem goes away:

    synchronized public void shutdown() {
        // Well, since java.util.logging has its own shutdown hook, this
        // might actually make it into the log or not...
        log.info(">>> Shutting down UPnP service...");

        Thread registryShutdown = new Thread() {
            @Override
            public void run() {
                getRegistry().shutdown();
            }
        };
        registryShutdown.start();
        getRouter().shutdown();
        getConfiguration().shutdown();

        log.info("<<< UPnP service shutdown completed");
    }
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

Christian Bauer
Administrator
Fixed this but with a join() to wait for the Registry shutdown on UpnpService shutdown.
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

bergstr
ok, testing..

BTW, is the join() really necesessary? As I described, in my app the shutdown also happens during configuration changes (the user turns the tablet from landscape to portrait, which causes android to shut down and recreate the activity). This may not be ideal, and there are ways to circumvent it, but it currently is as it is. Having a (max) 5 second wait in there - on the Android UI thread - doesn't seem like a good idea..
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

Christian Bauer
Administrator
We need to wait for the Registry shutting down and sending all its BYEBYE messages. If we don't wait, UPnP notification would be broken. You definitely do not want to restart the UpnpService on a screen orientation change, other control points would see your devices disappear/reappear all the time (ALIVE, BYEBYE).

Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

bergstr
Christian Bauer wrote
You definitely do not want to restart the UpnpService on a screen orientation change, other control points would see your devices disappear/reappear all the time (ALIVE, BYEBYE).
granted. I only have one local renderer though, and was previously using the #setAdvertising(false) option, which Michael Pujos's branch provided..

5 seconds on the UI thread is still something that will most likely not go through, even on final shutdown..
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

Christian Bauer
Administrator
All of Michael's features have been migrated to master in December.

You do realize that it's not waiting 5 seconds every time, only a maximum of 5 seconds.
Reply | Threaded
Open this post in threaded view
|

Re: Crash on exit if I unbind

bergstr
Christian Bauer wrote
All of Michael's features have been migrated to master in December.
this one hasn't, believe me.

Christian Bauer wrote
You do realize that it's not waiting 5 seconds every time, only a maximum of 5 seconds.
sure, but still.. Heres 2 interesting quotes from the android docs:
Generally, 100 to 200ms is the threshold beyond which users will perceive slowness in an application
above that, the system may show an "Application Not Responding" dialog. And
Although it's more complicated than AsyncTask, you might want to instead create your own Thread or HandlerThread class. If you do, you should set the thread priority to "background" priority by calling Process.setThreadPriority() and passing THREAD_PRIORITY_BACKGROUND. If you don't set the thread to a lower priority this way, then the thread could still slow down your app because it operates at the same priority as the UI thread by default.
12