search

schwabe / ics-openvpn

OpenVPN for Android
3.31k stars 1.19k forks source link

Android TV boot loop #814

Closed hoshsadiq closed 5 years ago

hoshsadiq commented 6 years ago

Currently causes a bootloop on my Android TV setup when enabling connect on boot, I'm happy to upload logs but not sure where to find them (I've already setup adb so just need the file location).

Android version: 7.0/kernel 3.10.79 Android vendor: PKG6.2671.0070EUA / BRAVIA_ATV2_EU-user 7.0 NRD91N.S90 Device: Sony Bravia KD-49XD8088 App version: 0.6.70 (installed from the app store so should be latest version)

ederbalmeida commented 6 years ago

It always happens on my xbr905e TV, when it starts.

schwabe commented 6 years ago

adb logcat on a connected pc might give some insight. I will try to reproduce this on my nivdia schield

hoshsadiq commented 6 years ago

I will try and get logs through adb logcat tonight and report back.

hoshsadiq commented 6 years ago

Here's the log right before it restarted: https://paste.ee/p/Zp2Ar With the above log, I took the following steps:

  1. Enable connect on boot
  2. Put TV in sleep mode (essentially pressing the power button, but it doesn't switch off)
  3. Wait about a minute
  4. Press the power button again to switch on

This led the TV to come out of sleep, then it completely switched off (as opposed to sleep), then i tried to adb connect as soon as I could after boot. This then continued to boot until it eventually restarted again (i.e. last line is because adb got disconnected due to restart).

There's a whole bunch of stacktraces but they don't look like they're from this app. Anyway, tried a few more times but this time I grepped on the pid of this app, no luck (see below).

$ adb logcat | grep " $(adb shell ps | grep de.blinkt.openvpn | awk '{print $2}') "
01-15 18:43:00.000  1843  2481 D PowerManagerNotifier: onWakeLockAcquired: flags=1073741825, tag="*alarm*", packageName=android, ownerUid=1000, ownerPid=1843, workSource=WorkSource{1000}
01-15 18:43:11.523  1843  3234 I ActivityManager: Start proc 4116:de.blinkt.openvpn/u0a183 for broadcast de.blinkt.openvpn/.OnBootReceiver
01-15 18:43:11.781  4116  4116 I art     : Starting a blocking GC AddRemoveAppImageSpace
01-15 18:43:11.988  1843  3249 I ActivityManager: Start proc 4182:de.blinkt.openvpn:openvpn/u0a183 for service de.blinkt.openvpn/.core.OpenVPNStatusService
01-15 18:43:12.101  4182  4182 I art     : Starting a blocking GC AddRemoveAppImageSpace
01-15 18:43:12.660  4182  4195 I art     : Background partial concurrent mark sweep GC freed 2708(161KB) AllocSpace objects, 277(5MB) LOS objects, 39% free, 3MB/5MB, paused 3.704ms total 116.003ms
01-15 18:43:12.815  4182  4272 I OpenVPN : Starting openvpn
01-15 18:43:14.384  4182  4337 I OpenGLRenderer: Initialized EGL, version 1.4
01-15 18:43:14.384  4182  4337 D OpenGLRenderer: Swap behavior 1
01-15 18:43:14.400  4182  4337 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
01-15 18:43:15.752  4182  4337 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
01-15 18:43:15.919  4182  4337 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
01-15 18:43:16.411  4182  4337 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
01-15 18:43:31.891  3243  4151 D MtkTvEvent_jni: <EIT_PF_ALL_UPDATE> arr_svl_id=1, arr_channel_id=61341825,i4_len = 93,b_is_present=1
01-15 18:43:31.904  3243  4151 D MtkTvEvent_jni: <EIT_PF_ALL_UPDATE> arr_svl_id=1, arr_channel_id=61341825,i4_len = 26,b_is_present=0
01-15 18:43:47.854  3124  5060 I ProcessCheckinRequest:     c: 1516041821965
01-15 18:43:50.119  1843  2716 I ActivityManager: Killing 4116:de.blinkt.openvpn/u0a183 (adj 906): empty #18
01-15 18:43:50.278  1843  3182 D ActivityManager: cleanUpApplicationRecord -- 4116
01-15 18:44:12.411  4182  4195 I art     : Background partial concurrent mark sweep GC freed 17376(562KB) AllocSpace objects, 68(1360KB) LOS objects, 39% free, 3MB/5MB, paused 1.093ms total 238.346ms
01-15 18:44:19.499  3897  6211 I MtkTvChannelList: DvbChannel[order=115, shortName=, BW=3, nwId=12339, progId=27456, symRate=0, mod=6, satRecId=0, nwName=London, sdtSvcTp=1, pvrDad=www.rt.com, HDTV=false, SDTV=false, Pay=false, hasBarker=false, isBarkerCh=false, nmrcSlctbl=true, svlId=1, svlRecId=114, chId=61341825, onId=9018, tsId=24640, svcId=27456, LCN=234, LCNIndex=0, LCNValue=234, majorNo=234, minorNo=0, svcName=RT, bcstTp=2, svcTp=1, bcstMdm=1, sigTp=DVBT, freq=529000000, nwMsk=8719, optMsk=4640, opt2Msk=64, epgVisible=true, visible=true, hidden=false, active=true, locked=false, deleted=false, prvData=[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], cstData=[0, 0, 0, 0, 0, 0, 0, 0]]
01-15 18:44:20.098  3897  6211 D MtkTvEvent : Enter getPresentEventInfoByChannelId, channelid = 61341825
01-15 18:44:20.105  3897  6211 D MtkTvEvent : MtkTvEventInfo [svlId=1, channelId=61341825, eventId=39050, startTime=1516041000, duration=1800, caption=false, freeCaMode=false, eventTitle=Renegade Inc., eventDetail=Renegade Inc. is a new kind of talk show for people who think differently. Ross Ashcroft brings together thinkers, writers, leaders and creatorswhoquestion and re-think the conventional wisdom. eventDetailshort=Renegade Inc. is a new kind of talk show for people who think differently. Ross Ashcroft brings together thinkers, writers, leaders and creatorswhoquestion and re-think the conventional wisdom., eventDetailextended=, guidanceMode=0, guidanceText=, caSystemId=[0, 0, 0, 0], eventCategoryNum=1, eventCategory=[32, 0, 0, 0, 0, 0, 0, 0], eventLinkage=[MtkTvEventLinkAge: Onid=0, tsId=0, svcId=0, MtkTvEventLinkAge: Onid=0, tsId=0, svcId=0, MtkTvEventLinkAge: Onid=0, tsId=0, svcId=0, MtkTvEventLinkAge: Onid=0, tsId=0, svcId=0], component=[MtkTvEventComponent: mStreamContent=1, mComponentType=1, mComponentTag=1,mLanguage=und, MtkTvEventComponent: mStreamContent=2, mComponentType=3, mComponentTag=2,mLanguage=eng, MtkTvEventComponent: mStreamContent=0, mComponentType=0, mComponentTag=0,mLanguage=, MtkTvEventComponent: mStreamContent=0, mComponentType=0, mComponentTag=0,mLanguage=, MtkTvEventComponent: mStreamContent=0, mComponentType=0, mComponentTag=0,mLanguage=, MtkTvEventComponent: mStreamContent=0, mComponentType=0, mComponentTag=0,mLanguage=, MtkTvEventComponent: mStreamContent=0, mComponentType=0, mComponentTag=0,mLanguage=, MtkTvEventComponent: mStreamContent=0, mComponentType=0, mComponentTag=0,mLanguage=], videoDefinition=2, hasMulitpleAudioStreamsFlag=false, hasHohAudioFlag=false, hasVisuallyImpaireAudioFlag=false, hasMultiChannelAudioFlag=false, hasHohSubtitleFlag=false, hasSubtitleFlag=false]
01-15 18:44:27.592  6284  6284 D Huey    : WfdPlayAnyWhereServer::init() PORT(41824) is assigned

second attempt (after it came back on):

$ adb connect 192.168.100.2
connected to 192.168.100.2:5555
$ adb logcat | grep " $(adb shell ps | grep de.blinkt.openvpn | awk '{print $2}') "
01-15 18:45:52.140  1741  3249 I ActivityManager: Start proc 4052:de.blinkt.openvpn/u0a183 for broadcast de.blinkt.openvpn/.OnBootReceiver
01-15 18:45:52.566  4052  4052 I art     : Starting a blocking GC AddRemoveAppImageSpace
01-15 18:45:52.780  1741  3220 I ActivityManager: Start proc 4139:de.blinkt.openvpn:openvpn/u0a183 for service de.blinkt.openvpn/.core.OpenVPNStatusService
01-15 18:45:53.048  4139  4139 I art     : Starting a blocking GC AddRemoveAppImageSpace
01-15 18:45:54.010  4139  4233 I OpenVPN : Starting openvpn
01-15 18:45:56.177  4139  4285 I OpenGLRenderer: Initialized EGL, version 1.4
01-15 18:45:56.178  4139  4285 D OpenGLRenderer: Swap behavior 1
01-15 18:45:56.204  4139  4285 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
01-15 18:45:57.082  4139  4285 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
01-15 18:45:57.333  4139  4285 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
01-15 18:45:57.649  4139  4285 D mali_winsys: EGLint new_window_surface(egl_winsys_display*, void*, EGLSurface, EGLConfig, egl_winsys_surface**, egl_color_buffer_format*, EGLBoolean) returns 0x3000
01-15 18:46:02.837  3968  4471 I MtkTvChannelList: DvbChannel[order=78, shortName=, BW=3, nwId=12339, progId=41392, symRate=0, mod=14, satRecId=0, nwName=London, sdtSvcTp=22, pvrDad=, HDTV=false, SDTV=true, Pay=false, hasBarker=false, isBarkerCh=false, nmrcSlctbl=true, svlId=1, svlRecId=78, chId=21495937, onId=9018, tsId=40960, svcId=41392, LCN=82, LCNIndex=0, LCNValue=82, majorNo=82, minorNo=0, svcName=Vintage TV, bcstTp=2, svcTp=1, bcstMdm=1, sigTp=DVBT2, freq=569000000, nwMsk=8719, optMsk=4640, opt2Msk=64, epgVisible=true, visible=true, hidden=false, active=true, locked=false, deleted=false, prvData=[0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0], cstData=[0, 0, 0, 0, 0, 0, 0, 0]]
^C

By the way, in the past 12 hours I observed a few other things: After an eventual successful start, it ended up switching off out of nowhere some 2 or 3 hours after the fact. Just now, minutes ago, I saw it switching on for no reason (Android logo showed for about 2 seconds) and switch back off almost immediately.

schwabe commented 5 years ago

This may still be an issue but nothing points to some concrete behaviour in my app that needs changing. Closing this for now until someone can present something I can actually work on.

hoshsadiq commented 5 years ago

No worries. I've lately found out Sony's Android TVs are quite buggy so have a feeling it's some crap they've done. Thanks for having a look anyway!