Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

svg loading segfaults on nexus 5x #234

Open
maho opened this issue Jun 1, 2017 · 17 comments
Open

svg loading segfaults on nexus 5x #234

maho opened this issue Jun 1, 2017 · 17 comments

Comments

@maho
Copy link
Contributor

maho commented Jun 1, 2017

also it segfaults on some quite new Xiaomi.

adb log:

2017-06-01 13:05:05.921 ASSERT: DEBUG : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
2017-06-01 13:05:05.921 ASSERT: DEBUG : Build fingerprint: 'google/bullhead/bullhead:7.1.2/N2G47O/3852959:user/release-keys'
2017-06-01 13:05:05.921 ASSERT: DEBUG : Revision: 'rev_1.0'
2017-06-01 13:05:05.921 ASSERT: DEBUG : ABI: 'arm'
2017-06-01 13:05:05.922 ASSERT: DEBUG : pid: 10781, tid: 10820, name: SDLThread  >>> org.test.myapp <<<
2017-06-01 13:05:05.922 ASSERT: DEBUG : signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x34
2017-06-01 13:05:05.922 ASSERT: DEBUG : r0 d2260654  r1 00000000  r2 d495e240  r3 e1ce820c
2017-06-01 13:05:05.922 ASSERT: DEBUG : r4 d495e294  r5 00008be7  r6 00000001  r7 00000060
2017-06-01 13:05:05.922 ASSERT: DEBUG : r8 d47f6500  r9 d495e294  sl 00000000  fp 00000000
2017-06-01 13:05:05.922 ASSERT: DEBUG : ip 00000000  sp d514eda8  lr e1bda1ff  pc e1bda204  cpsr 80070030
2017-06-01 13:05:05.931 ASSERT: DEBUG : backtrace:
2017-06-01 13:05:05.932 ASSERT: DEBUG : #00 pc 000d3204  /vendor/lib/egl/libGLESv2_adreno.so
2017-06-01 13:05:05.932 ASSERT: DEBUG : #01 pc 000d79bb  /vendor/lib/egl/libGLESv2_adreno.so (_ZN21EsxGlApiParamValidate14GlDrawElementsEP11EsxDispatchjijPKv+122)
2017-06-01 13:05:05.932 ASSERT: DEBUG : #02 pc 00096f83  /vendor/lib/egl/libGLESv2_adreno.so (glDrawElements+34)
2017-06-01 13:05:05.932 ASSERT: DEBUG : #03 pc 00003417  /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/batching.so

Full log in https://pastebin.com/A0kt1pq2

Code which segfaults: https://github.com/mahomahomaho/kivent-segfault-issue (it's a bit modified example no 11). I have commented out

    size_of_batches: 786, 
    max_batches: 400,
    size_of_component_block: 786

because they caused memory error before app started on that android. And decreased isze of gameworld and indexes. Maybe it's the reason? What should be proper values?

Anyway - it doesn't crash on all androids, only on Nexus 5x, some Xiaomi (I don't know exact data) so far.

Steps to reproduce:

  1. clone https://github.com/mahomahomaho/kivent-segfault-issue
  2. buildozer andoird debug
  3. upload .apk to nexus5x or similar and run
@maho
Copy link
Contributor Author

maho commented Jun 2, 2017

What I discovered, is that in this line: https://github.com/kivy/kivent/blob/master/modules/core/kivent_core/rendering/batching.pyx#L215 - indices.data_size is ~182000 on Nexus, while 96 on other phones and on linux.

I have no idea where such strange indices.data_size comes from

@Kovak
Copy link
Contributor

Kovak commented Jun 2, 2017

Ok a little bit of data dump to help solve this, not certain on the exact cause yet

The maximum number of indices that can be uploaded in ES2 is 65,535.

The size of a batch should be set so that it is not greater than 65535 * the size of the vertex format. This is the most important number to set when it comes to rendering, otherwsie batching could try to make a too large of batch.

This issue also reminds me of: kivy/kivy#3693

@maho
Copy link
Contributor Author

maho commented Jun 2, 2017

oh man, I have no idea how to access to indices memory ;)

But I noticed that on linux I have also indices.data_size=1828864 , but ony first time, and apparently it doesn't make any problem for OpenGL, next calls have data_size=96

@Kovak
Copy link
Contributor

Kovak commented Jun 2, 2017

I wonder if we have something that is not initialized properly on the first call.

@maho
Copy link
Contributor Author

maho commented Jun 2, 2017

I think so, set_index_count_for_frame is called with index_count=48 , BUT draw_frame is called BEFORE set_index_count_for_frame.....

@Kovak
Copy link
Contributor

Kovak commented Jun 2, 2017

ooo that is not supposed to happen! Will need to make sure things happen in the right order.

@maho
Copy link
Contributor Author

maho commented Jun 4, 2017

At first I thought that that first draw_frame tries to draw junk before something is initialized. So I make draw_frame just skip until set_index_count_for_frame is called. And still segfaults.

I would try to dump memory in vertices and indices, but ... I have no idea how should I do it. Any hint? Or better - code to copy&paste? :)

@maho
Copy link
Contributor Author

maho commented Jun 6, 2017

ok, I know how to dump, and I will dump soon.

And I know now, that it's not matter of not initialized batch, and it's NOT matter of SVG. I tried example with polydraw (no svg involved) and result is the same.

I will post memdump soon I hope.

@maho
Copy link
Contributor Author

maho commented Jun 6, 2017

So,
I ran https://github.com/kivy/kivent/tree/master/examples/12_drawing_shapes example, with decreased memory in .kv to 600kb , and with enabled DEBUG logging, and with this branch of kivent: https://github.com/mahomahomaho/kivent/tree/testcase-segfault-logging on Nexus5x,

It dumped buffer bound by indices.bind() and vertices.bind() - log is in https://transfer.sh/ryjYP/TestObject_Log_LG_Nexus_5X_real_06-06-2017_10-34-31.txt

Log is about creating simple triangle on the screen - it generates creating buffer with 262 thousands of zeroes.

@maho
Copy link
Contributor Author

maho commented Jun 7, 2017

it's definitively not matter of not initialized data_size of index_vbo. When I set it to 0 at the start, first call to glDrawElements passes and next fails. While that next looks legit:

14:20:53 I python : [DEBUG  ] glBufferSubData(target=34963 data_size=0L) (will dump first 300)
14:20:53 I python : [INFO   ] glDrawElements(mode=4 indices.data_size=0)
14:20:53 I python : [INFO   ] after glDrawElements
14:20:53 I python : [INFO   ] after vertices undbind
14:20:53 I python : [INFO   ] after indices unbind
14:20:53 I python : [DEBUG  ] Renderer.update for batch_key=4294967295
14:20:53 I python : [DEBUG  ] batches = [<kivent_core.rendering.batching.IndexedBatch object at 0xd6b860f0>]
14:20:53 I python : [DEBUG  ] for batch = <kivent_core.rendering.batching.IndexedBatch object at 0xd6b860f0>, static_rendering=False force_update=False
14:20:53 I python : [DEBUG  ] set_index_count_for_frame(index_count=3)
14:20:53 I python : [DEBUG  ] self.current_frame=2 self.frame_count=1
14:20:53 I python : [DEBUG  ] glBufferSubData(target=34962 data_size=262144L) (will dump first 300)
14:20:53 I python : 00000000: 00 C0 11 44 00 40 3E 44  FF 00 00 FF 00 40 37 44  ...D.@>D.....@7D
14:20:53 I python : 00000010: 00 40 3E 44 00 FF 00 FF  00 80 24 44 00 C0 63 44  .@>D......$D..cD
14:20:53 I python : 00000020: 00 00 FF FF 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 00000030: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 00000040: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 00000050: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 00000060: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 00000070: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 00000080: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 00000090: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 000000A0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 000000B0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 000000C0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 000000D0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 000000E0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 000000F0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 00000100: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 00000110: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
14:20:53 I python : 00000120: 00 00 00 00 00 00 00 00  00 00 00 00              ............
14:20:53 I python : [DEBUG  ] glBufferData(target=34963 data_size=6L usage=35040) (will dump first 300)
14:20:53 I python : 00000000: 00 00 01 00 02 00                                 ......
14:20:53 I python : [INFO   ] glDrawElements(mode=4 indices.data_size=6)
14:20:53 I python : --------- beginning of crash
14:20:53 A libc : Fatal signal 11 (SIGSEGV), code 1, fault addr 0x34 in tid 14163 (SDLThread)
14:20:53 W  : debuggerd: handling request: pid=14143 uid=10133 gid=10133 tid=14163
14:20:53 W debuggerd : type=1400 audit(0.0:68): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:69): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:70): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:71): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:72): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:73): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:74): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:75): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:76): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:77): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:78): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:79): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:80): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:81): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:82): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:83): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:84): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:85): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:86): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:87): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 W debuggerd : type=1400 audit(0.0:88): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=385504 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
14:20:53 I TOOLKIT SERVICE : Request body '{"id":"1496830939971","type":"GET_SCREEN_ORIENTATION"}'
14:20:53 I DEVICE MANAGER : {"id":"1496830939971","type":"GET_SCREEN_ORIENTATION"}
14:20:53 I TOOLKIT SERVICE : Responding to client with: '{"id":"1496830939971","orientation":"PORTRAIT"}'
14:20:53 I art : Starting a blocking GC Explicit
14:20:53 A DEBUG : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
14:20:53 A DEBUG : Build fingerprint: 'google/bullhead/bullhead:7.1.2/N2G47O/3852959:user/release-keys'
14:20:53 A DEBUG : Revision: 'rev_1.0'
14:20:53 A DEBUG : ABI: 'arm'
14:20:53 A DEBUG : pid: 14143, tid: 14163, name: SDLThread  >>> org.test.myapp <<<
14:20:53 A DEBUG : signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x34
14:20:53 A DEBUG : r0 d984e254  r1 00000000  r2 d9ccee80  r3 e78b720c
14:20:53 A DEBUG : r4 d9cceed4  r5 00008be7  r6 00000001  r7 00000060
14:20:53 A DEBUG : r8 da5523c0  r9 d9cceed4  sl 00000000  fp 00000000
14:20:53 A DEBUG : ip 00000000  sp db560d78  lr e77a91ff  pc e77a9204  cpsr 800f0030
14:20:53 A DEBUG : backtrace:
14:20:53 A DEBUG : #00 pc 000d3204  /vendor/lib/egl/libGLESv2_adreno.so
14:20:53 A DEBUG : #01 pc 000d79bb  /vendor/lib/egl/libGLESv2_adreno.so (_ZN21EsxGlApiParamValidate14GlDrawElementsEP11EsxDispatchjijPKv+122)
14:20:53 A DEBUG : #02 pc 00096f83  /vendor/lib/egl/libGLESv2_adreno.so (glDrawElements+34)
14:20:53 A DEBUG : #03 pc 00006e27  /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/batching.so

I'm not an expert of float representation of vertices, but I don't see anything wrong with data in logs.
Any idea why it fails in adreno but not in other opengl providers? maybe we don't call something which should be called first?

@maho
Copy link
Contributor Author

maho commented Jun 7, 2017

and one thought - maybe there is something wrong with shader?

@Kovak
Copy link
Contributor

Kovak commented Jun 7, 2017

I don't think the issue is with the way the vertex data is formatted. The traceback seems to point to possibly a bug in the gl implementation. I'm seeing a lot of similar issues on SO with the adreno drivers. There is probably a work around we can do if we can discover what it is.

One thing that might help, if you set debug = True before compiling
https://github.com/kivy/kivent/blob/master/modules/core/kivent_core/gameworld.pyx#L25

you should get debug logs for all our GL calls which might help us track down an error.

@maho
Copy link
Contributor Author

maho commented Jun 9, 2017

I didn't find any effect of setting gameworld.debug to True
but, when I set https://github.com/kivy/kivy/blob/master/kivy/graphics/cgl.pyx#L94 , then I get blank screen in nexus5.

@maho
Copy link
Contributor Author

maho commented Jun 9, 2017

I also get blank screen when I set KIVY_GL_DEBUG=1 in linux

I think my queue of ideas drained out.

I read somewhere that OpenGL ES is ansynchronous. Is it possible that glDrawElements is executed before glSetBuffer takes effect? Or sth like that?

@Kovak
Copy link
Contributor

Kovak commented Jun 9, 2017

You get no additional logs when you set gameworld.debug to True and recompile?
The other KIVY_GL_DEBUG is different. OpenGL of all types is technically a client, server interaction; but there are additional limits on that with ES and most versions of GL prior to the newest where only a single thread can communicate with the GL context. It is far more likely that there is a bug in the Adreno drivers and we need to find a work around (adreno drivers are notoriously inconsistent and incomplete)

@maho
Copy link
Contributor Author

maho commented Jun 12, 2017

I don't see anything more than I added. Below is the log, and code which is run (kivent both with app) is in https://github.com/mahomahomaho/kivent/tree/testcase-segfault-logging (app is examples/12-....)

2017-06-12 11:50:53.853	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253940612","closePopups":true}'
2017-06-12 11:50:53.855	INFO:	PlayCommon : [451] com.google.android.play.a.g.e(220): Preparing logs for uploading
2017-06-12 11:50:53.856	INFO:	PlayCommon : [451] com.google.android.play.a.g.e(224): No file ready to send
2017-06-12 11:50:53.899	WARN:	libEGL : EGLNativeWindowType 0x7eceaf8210 disconnect failed
2017-06-12 11:50:54.441	DEBUG:	AndroidRuntime : >>>>>> START com.android.internal.os.RuntimeInit uid 2000 <<<<<<
2017-06-12 11:50:54.446	DEBUG:	AndroidRuntime : CheckJNI is OFF
2017-06-12 11:50:54.524	DEBUG:	ICU : No timezone override file found: /data/misc/zoneinfo/current/icu/icu_tzdata.dat
2017-06-12 11:50:54.559	INFO:	Radio-JNI : register_android_hardware_Radio DONE
2017-06-12 11:50:54.571	DEBUG:	AndroidRuntime : Calling main entry com.android.commands.pm.Pm
2017-06-12 11:50:54.604	INFO:	art : System.exit called, status: 0
2017-06-12 11:50:54.604	INFO:	AndroidRuntime : VM exiting with result code 0.
2017-06-12 11:50:54.610	WARN:	MessageQueue : Handler (android.os.Handler) {917e108} sending message to a Handler on a dead thread
2017-06-12 11:50:54.610	WARN:	MessageQueue : java.lang.IllegalStateException: Handler (android.os.Handler) {917e108} sending message to a Handler on a dead thread
2017-06-12 11:50:54.610	WARN:	MessageQueue : at android.os.MessageQueue.enqueueMessage(MessageQueue.java:543)
2017-06-12 11:50:54.610	WARN:	MessageQueue : at android.os.Handler.enqueueMessage(Handler.java:643)
2017-06-12 11:50:54.610	WARN:	MessageQueue : at android.os.Handler.sendMessageAtTime(Handler.java:612)
2017-06-12 11:50:54.610	WARN:	MessageQueue : at android.os.Handler.sendMessageDelayed(Handler.java:582)
2017-06-12 11:50:54.610	WARN:	MessageQueue : at android.os.Handler.post(Handler.java:338)
2017-06-12 11:50:54.610	WARN:	MessageQueue : at android.os.ResultReceiver$MyResultReceiver.send(ResultReceiver.java:57)
2017-06-12 11:50:54.610	WARN:	MessageQueue : at com.android.internal.os.IResultReceiver$Stub.onTransact(IResultReceiver.java:58)
2017-06-12 11:50:54.610	WARN:	MessageQueue : at android.os.Binder.execTransact(Binder.java:565)
2017-06-12 11:50:55.384	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:50:55.439	INFO:	art : Explicit concurrent mark sweep GC freed 148(8KB) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 250us total 54.670ms
2017-06-12 11:50:56.889	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:50:56.942	INFO:	art : Explicit concurrent mark sweep GC freed 76(4KB) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 293us total 53.141ms
2017-06-12 11:50:57.997	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253944759","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:57.998	INFO:	DEVICE MANAGER : {"id":"1497253944759","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.002	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253944759","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.011	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253944774","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.011	INFO:	DEVICE MANAGER : {"id":"1497253944774","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.014	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253944774","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.061	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253944824","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.061	INFO:	DEVICE MANAGER : {"id":"1497253944824","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.063	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253944824","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.112	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253944873","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.112	INFO:	DEVICE MANAGER : {"id":"1497253944873","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.116	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253944873","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.168	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253944929","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.168	INFO:	DEVICE MANAGER : {"id":"1497253944929","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.173	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253944929","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.224	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253944985","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.224	INFO:	DEVICE MANAGER : {"id":"1497253944985","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.230	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253944985","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.281	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253945042","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.281	INFO:	DEVICE MANAGER : {"id":"1497253945042","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.286	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253945042","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.341	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253945101","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.341	INFO:	DEVICE MANAGER : {"id":"1497253945101","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.345	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253945101","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.393	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:50:58.400	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253945158","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.400	INFO:	DEVICE MANAGER : {"id":"1497253945158","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.404	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253945158","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.448	INFO:	art : Explicit concurrent mark sweep GC freed 73(3KB) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 345us total 54.521ms
2017-06-12 11:50:58.451	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253945214","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.451	INFO:	DEVICE MANAGER : {"id":"1497253945214","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.453	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253945214","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.500	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253945261","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.500	INFO:	DEVICE MANAGER : {"id":"1497253945261","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.505	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253945261","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.554	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253945315","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.554	INFO:	DEVICE MANAGER : {"id":"1497253945315","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.559	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253945315","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.610	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253945371","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.610	INFO:	DEVICE MANAGER : {"id":"1497253945371","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.615	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253945371","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.667	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253945428","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.667	INFO:	DEVICE MANAGER : {"id":"1497253945428","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.673	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253945428","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.724	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253945485","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.724	INFO:	DEVICE MANAGER : {"id":"1497253945485","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.731	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253945485","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.778	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253945541","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.778	INFO:	DEVICE MANAGER : {"id":"1497253945541","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.781	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253945541","orientation":"PORTRAIT"}'
2017-06-12 11:50:58.831	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253945593","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:58.831	INFO:	DEVICE MANAGER : {"id":"1497253945593","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:58.836	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253945593","orientation":"PORTRAIT"}'
2017-06-12 11:50:59.208	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253945968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:59.208	INFO:	DEVICE MANAGER : {"id":"1497253945968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:59.213	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253945968","orientation":"PORTRAIT"}'
2017-06-12 11:50:59.707	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253946468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:50:59.708	INFO:	DEVICE MANAGER : {"id":"1497253946468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:50:59.712	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253946468","orientation":"PORTRAIT"}'
2017-06-12 11:50:59.896	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:50:59.942	INFO:	art : Explicit concurrent mark sweep GC freed 54(2840B) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 287us total 45.942ms
2017-06-12 11:51:00.204	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253946968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:00.204	INFO:	DEVICE MANAGER : {"id":"1497253946968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:00.207	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253946968","orientation":"PORTRAIT"}'
2017-06-12 11:51:00.707	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253947468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:00.708	INFO:	DEVICE MANAGER : {"id":"1497253947468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:00.712	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253947468","orientation":"PORTRAIT"}'
2017-06-12 11:51:01.207	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253947968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:01.207	INFO:	DEVICE MANAGER : {"id":"1497253947968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:01.212	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253947968","orientation":"PORTRAIT"}'
2017-06-12 11:51:01.398	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:01.445	INFO:	art : Explicit concurrent mark sweep GC freed 8(272B) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 257us total 46.696ms
2017-06-12 11:51:01.707	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253948468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:01.708	INFO:	DEVICE MANAGER : {"id":"1497253948468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:01.711	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253948468","orientation":"PORTRAIT"}'
2017-06-12 11:51:02.208	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253948968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:02.208	INFO:	DEVICE MANAGER : {"id":"1497253948968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:02.213	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253948968","orientation":"PORTRAIT"}'
2017-06-12 11:51:02.708	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253949468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:02.708	INFO:	DEVICE MANAGER : {"id":"1497253949468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:02.712	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253949468","orientation":"PORTRAIT"}'
2017-06-12 11:51:02.899	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:02.946	INFO:	art : Explicit concurrent mark sweep GC freed 8(272B) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 251us total 46.751ms
2017-06-12 11:51:03.207	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253949968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:03.207	INFO:	DEVICE MANAGER : {"id":"1497253949968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:03.213	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253949968","orientation":"PORTRAIT"}'
2017-06-12 11:51:03.707	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253950468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:03.707	INFO:	DEVICE MANAGER : {"id":"1497253950468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:03.712	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253950468","orientation":"PORTRAIT"}'
2017-07-24 11:51:04.258	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253951017","type":"GET_SCREEN_ORIENTATION"}'
2017-07-12 11:51:04.258	INFO:	DEVICE MANAGER : {"id":"1497253951017","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:04.265	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253951017","orientation":"PORTRAIT"}'
2017-06-12 11:51:04.400	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:04.449	INFO:	art : Explicit concurrent mark sweep GC freed 8(272B) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 362us total 48.045ms
2017-06-12 11:51:04.708	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253951468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:04.709	INFO:	DEVICE MANAGER : {"id":"1497253951468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:04.714	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253951468","orientation":"PORTRAIT"}'
2017-06-12 11:51:05.207	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253951968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:05.207	INFO:	DEVICE MANAGER : {"id":"1497253951968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:05.212	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253951968","orientation":"PORTRAIT"}'
2017-06-12 11:51:05.708	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253952468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:05.708	INFO:	DEVICE MANAGER : {"id":"1497253952468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:05.714	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253952468","orientation":"PORTRAIT"}'
2017-06-12 11:51:05.903	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:05.957	INFO:	art : Explicit concurrent mark sweep GC freed 8(272B) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 356us total 53.180ms
2017-06-12 11:51:06.209	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253952968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:06.209	INFO:	DEVICE MANAGER : {"id":"1497253952968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:06.214	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253952968","orientation":"PORTRAIT"}'
2017-06-12 11:51:06.707	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253953468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:06.708	INFO:	DEVICE MANAGER : {"id":"1497253953468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:06.712	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253953468","orientation":"PORTRAIT"}'
2017-06-12 11:51:07.209	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253953968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:07.209	INFO:	DEVICE MANAGER : {"id":"1497253953968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:07.212	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253953968","orientation":"PORTRAIT"}'
2017-06-12 11:51:07.408	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:07.456	INFO:	art : Explicit concurrent mark sweep GC freed 8(272B) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 420us total 47.587ms
2017-06-12 11:51:07.713	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253954468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:07.713	INFO:	DEVICE MANAGER : {"id":"1497253954468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:07.715	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253954468","orientation":"PORTRAIT"}'
2017-06-12 11:51:08.207	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253954968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:08.207	INFO:	DEVICE MANAGER : {"id":"1497253954968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:08.213	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253954968","orientation":"PORTRAIT"}'
2017-06-12 11:51:08.709	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253955468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:08.709	INFO:	DEVICE MANAGER : {"id":"1497253955468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:08.715	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253955468","orientation":"PORTRAIT"}'
2017-06-12 11:51:08.911	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:08.960	INFO:	art : Explicit concurrent mark sweep GC freed 8(272B) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 334us total 48.884ms
2017-06-12 11:51:09.209	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253955968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:09.209	INFO:	DEVICE MANAGER : {"id":"1497253955968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:09.216	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253955968","orientation":"PORTRAIT"}'
2017-06-12 11:51:09.709	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253956468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:09.709	INFO:	DEVICE MANAGER : {"id":"1497253956468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:09.715	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253956468","orientation":"PORTRAIT"}'
2017-06-12 11:51:10.207	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253956968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:10.207	INFO:	DEVICE MANAGER : {"id":"1497253956968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:10.212	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253956968","orientation":"PORTRAIT"}'
2017-06-12 11:51:10.347	DEBUG:	AndroidRuntime : >>>>>> START com.android.internal.os.RuntimeInit uid 2000 <<<<<<
2017-06-12 11:51:10.354	DEBUG:	AndroidRuntime : CheckJNI is OFF
2017-06-12 11:51:10.411	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:10.422	DEBUG:	ICU : No timezone override file found: /data/misc/zoneinfo/current/icu/icu_tzdata.dat
2017-06-12 11:51:10.451	INFO:	Radio-JNI : register_android_hardware_Radio DONE
2017-06-12 11:51:10.456	INFO:	art : Explicit concurrent mark sweep GC freed 8(272B) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 225us total 44.187ms
2017-06-12 11:51:10.462	DEBUG:	AndroidRuntime : Calling main entry com.android.commands.pm.Pm
2017-06-12 11:51:10.482	INFO:	 : free_cache(9282121) avail 23970156544
2017-06-12 11:51:10.657	DEBUG:	WifiStateMachine : CMD_AUTO_CONNECT sup state DisconnectedState my state DisconnectedState nid=0 roam=false
2017-06-12 11:51:10.657	DEBUG:	WifiStateMachine : CMD_AUTO_CONNECT will save config -> "TestObject Devices" nid=0
2017-06-12 11:51:10.704	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253957468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:10.704	INFO:	DEVICE MANAGER : {"id":"1497253957468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:10.705	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253957468","orientation":"PORTRAIT"}'
2017-09-03 11:51:10.831	DEBUG:	WifiNetworkHistory : saving network history: "TestObject Devices"WPA_PSK gw: null Network Selection-status: NETWORK_SELECTION_ENABLED ephemeral=false choice:null link:0 status:2 nid:0 hasEverConnected: true
2017-04-12 11:00:10.840	DEBUG:	WifiStateMachine : CMD_AUTO_CONNECT did save config ->  nid=0
2017-06-12 11:51:10.843	INFO:	wpa_supplicant : wlan0: Trying to associate with SSID 'TestObject Devices'
2017-06-12 11:51:10.843	DEBUG:	WifiNetworkHistory : saving network history: "TestObject Devices"WPA_PSK gw: null Network Selection-status: NETWORK_SELECTION_ENABLED ephemeral=false choice:null link:0 status:2 nid:0 hasEverConnected: true
2017-06-12 11:51:10.918	INFO:	wpa_supplicant : wlan0: Associated with 92:2a:a8:48:62:19
2017-06-12 11:51:10.920	INFO:	wpa_supplicant : wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
2017-06-12 11:51:10.927	INFO:	wpa_supplicant : wlan0: WPA: Key negotiation completed with 92:2a:a8:48:62:19 [PTK=CCMP GTK=CCMP]
2017-06-12 11:51:10.927	INFO:	wpa_supplicant : wlan0: CTRL-EVENT-CONNECTED - Connection to 92:2a:a8:48:62:19 completed [id=0 id_str=%7B%22creatorUid%22%3A%2210124%22%2C%22configKey%22%3A%22%5C%22TestObject+Devices%5C%22WPA_PSK%22%7D]
2017-06-12 11:51:10.937	DEBUG:	ConnectivityService : registerNetworkAgent NetworkAgentInfo{ ni{[type: WIFI[], state: CONNECTING/CONNECTING, reason: (unspecified), extra: "TestObject Devices", failover: false, available: true, roaming: false, metered: false]}  network{103}  nethandle{442398067422}  lp{{LinkAddresses: []  Routes: [] DnsAddresses: [] Domains: null MTU: 0}}  nc{[ Transports: WIFI Capabilities: NOT_METERED&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN LinkUpBandwidth>=1048576Kbps LinkDnBandwidth>=1048576Kbps]}  Score{20}  everValidated{false}  lastValidated{false}  created{false} lingering{false} explicitlySelected{false} acceptUnvalidated{false} everCaptivePortalDetected{false} lastCaptivePortalDetected{false} }
2017-06-12 11:51:10.937	DEBUG:	ConnectivityService : NetworkAgentInfo [WIFI () - 103] EVENT_NETWORK_INFO_CHANGED, going from null to CONNECTING
2017-06-12 11:51:10.942	DEBUG:	wifi : APF version supported: 2
2017-06-12 11:51:10.942	DEBUG:	wifi : Maximum APF program size: 4096
2017-06-12 11:51:10.944	DEBUG:	WifiStateMachine : Start Dhcp Watchdog 4
2017-06-12 11:51:10.952	DEBUG:	WifiNative-wlan0 : configureNeighborDiscoveryOffload(true)
2017-06-12 11:51:10.967	DEBUG:	ApfFilter : (wlan0): begin monitoring
2017-06-12 11:51:10.981	DEBUG:	DhcpClient : Receive thread started
2017-06-12 11:51:10.986	DEBUG:	DhcpClient : Broadcasting DHCPDISCOVER
2017-06-12 11:51:11.038	INFO:	PackageManager.DexOptimizer : Running dexopt (dex2oat) on: /data/app/vmdl1326965938.tmp/base.apk pkg=org.test.myapp isa=arm vmSafeMode=false debuggable=true target-filter=interpret-only oatDir = /data/app/vmdl1326965938.tmp/oat sharedLibraries=null
2017-06-12 11:51:11.078	INFO:	dex2oat : /system/bin/dex2oat --compiler-filter=interpret-only -j4 --debuggable
2017-06-12 11:51:11.205	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253957968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:11.205	INFO:	DEVICE MANAGER : {"id":"1497253957968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:11.208	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253957968","orientation":"PORTRAIT"}'
2017-06-12 11:51:11.242	INFO:	dex2oat : dex2oat took 164.953ms (threads: 4) arena alloc=4KB (4688B) java alloc=252KB (258696B) native alloc=1180KB (1208512B) free=2MB (2985792B)
2017-06-12 11:51:11.444	DEBUG:	installd : Detected label change from u:object_r:system_data_file:s0 to u:object_r:app_data_file:s0:c512,c768 at /data/data/org.test.myapp; running recursive restorecon
2017-06-12 11:51:11.446	DEBUG:	installd : Detected label change from u:object_r:system_data_file:s0 to u:object_r:app_data_file:s0:c512,c768 at /data/user_de/0/org.test.myapp; running recursive restorecon
2017-06-12 11:51:11.451	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:11.579	INFO:	art : Explicit concurrent mark sweep GC freed 115731(6MB) AllocSpace objects, 25(828KB) LOS objects, 33% free, 16MB/25MB, paused 1.792ms total 128.140ms
2017-06-12 11:51:11.580	ERROR:	 : Couldn't opendir /data/app/vmdl1326965938.tmp: No such file or directory
2017-06-12 11:51:11.603	INFO:	InputReader : Reconfiguring input devices.  changes=0x00000010
2017-06-12 11:51:11.611	WARN:	PackageManager : Unable to load service info ResolveInfo{1a7c626 mobicip.com.safeBrowserff/org.mozilla.gecko.fxa.authenticator.FxAccountAuthenticatorService m=0x108000}
2017-06-12 11:51:11.614	INFO:	art : System.exit called, status: 0
2017-06-12 11:51:11.614	INFO:	AndroidRuntime : VM exiting with result code 0.
2017-06-12 11:51:11.629	DEBUG:	CarrierSvcBindHelper : No carrier app for: 0
2017-06-12 11:51:11.630	DEBUG:	CarrierConfigLoader : mHandler: 9 phoneId: 0
2017-06-12 11:51:11.640	DEBUG:	RegisteredNfcFServicesCache : Service unchanged, not updating
2017-06-12 11:51:11.657	INFO:	Finsky : [1] com.google.android.finsky.utils.PermissionPolicies$PermissionPolicyService.onStartCommand(18): post-install permissions check for org.test.myapp
2017-06-12 11:51:11.663	WARN:	PackageManager : Unable to load service info ResolveInfo{6198f55 mobicip.com.safeBrowserff/org.mozilla.gecko.fxa.sync.FxAccountSyncService m=0x108000}
2017-06-12 11:51:11.670	INFO:	Finsky : [1] com.google.android.finsky.utils.ao.run(11): Package state data is missing for org.test.myapp
2017-06-12 11:51:11.676	INFO:	WearableService : onCreate - Wear is not available on this device.
2017-06-12 11:51:11.686	DEBUG:	WearableService : onGetService - Wear is not available on this device.
2017-06-12 11:51:11.689	ERROR:	Finsky : [1] com.google.android.finsky.wear.bl.a(3): onConnectionFailed: ConnectionResult{statusCode=API_UNAVAILABLE, resolution=null, message=null}
2017-06-12 11:51:11.691	WARN:	Finsky : [1] com.google.android.finsky.wear.aj.run(9): Dropping command=auto_install due to Gms not connected
2017-06-12 11:51:11.699	WARN:	Finsky : [1] com.google.android.finsky.wear.aj.run(9): Dropping command=send_installed_apps due to Gms not connected
2017-06-12 11:51:11.704	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253958468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:11.704	INFO:	DEVICE MANAGER : {"id":"1497253958468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:11.705	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253958468","orientation":"PORTRAIT"}'
2017-06-12 11:51:11.714	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253958478","type":"CLOSE_POPUPS"}'
2017-06-12 11:51:11.714	INFO:	DEVICE MANAGER : {"id":"1497253958478","type":"CLOSE_POPUPS"}
2017-06-12 11:51:11.718	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253958478","closePopups":true}'
2017-06-12 11:51:11.745	DEBUG:	Wear_Controller : Received broadcast action=android.intent.action.PACKAGE_ADDED and uri=org.test.myapp
2017-06-12 11:51:11.784	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253958549","type":"CLOSE_POPUPS"}'
2017-06-12 11:51:11.784	INFO:	DEVICE MANAGER : {"id":"1497253958549","type":"CLOSE_POPUPS"}
2017-06-12 11:51:11.786	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253958549","closePopups":true}'
2017-06-12 11:51:11.819	INFO:	Icing : App usage reports: 2
2017-06-12 11:51:11.819	INFO:	Icing : Usage reports 2 indexed 0 rejected 0 imm upload false
2017-06-12 11:51:11.831	INFO:	TOOLKIT SERVICE : Request body '{"package":"org.test.myapp","id":"1497253958594","type":"LAUNCH_APP"}'
2017-06-12 11:51:11.831	INFO:	DEVICE MANAGER : {"package":"org.test.myapp","id":"1497253958594","type":"LAUNCH_APP"}
2017-06-12 11:51:11.833	INFO:	art : Do full code cache collection, code=250KB, data=240KB
2017-06-12 11:51:11.834	INFO:	art : Starting a blocking GC JitCodeCache
2017-06-12 11:51:11.834	INFO:	art : After code cache collection, code=234KB, data=195KB
2017-06-12 11:51:11.835	INFO:	ActivityManager : START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10000000 pkg=org.test.myapp cmp=org.test.myapp/org.kivy.android.PythonActivity} from uid 10124 on display 0
2017-06-12 11:51:11.845	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253958594","launchApp":true}'
2017-06-12 11:51:11.854	INFO:	Icing : Usage reports 0 indexed 0 rejected 0 imm upload false
2017-06-12 11:51:11.859	INFO:	ActivityManager : Start proc 9536:org.test.myapp/u0a132 for activity org.test.myapp/org.kivy.android.PythonActivity
2017-06-12 11:51:11.862	INFO:	art : Late-enabling -Xcheck:jni
2017-06-12 11:51:11.914	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:11.940	INFO:	art : Explicit concurrent mark sweep GC freed 254(62KB) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 157us total 26.250ms
2017-06-12 11:51:11.941	INFO:	eLock : pkgname_before:com.google.android.googlequicksearchbox  class:org.test.myapp  isFingerActivityCreated:false   isCalling:false
2017-06-12 11:51:11.990	DEBUG:	DhcpClient : Received packet: 78:f8:82:9e:e9:a4 OFFER, ip /10.252.132.159, mask /255.255.240.0, DNS servers: /10.252.143.254 , gateways [/10.252.143.254] lease time 7200, domain localdomain
2017-06-12 11:51:11.991	DEBUG:	DhcpClient : Got pending lease: IP address 10.252.132.159/20 Gateway 10.252.143.254  DNS servers: [ 10.252.143.254 ] Domains localdomain DHCP server /10.252.143.254 Vendor info null lease 7200 seconds
2017-06-12 11:51:11.993	DEBUG:	DhcpClient : Broadcasting DHCPREQUEST ciaddr=0.0.0.0 request=10.252.132.159 serverid=10.252.143.254
2017-06-12 11:51:12.000	DEBUG:	DhcpClient : Received packet: 78:f8:82:9e:e9:a4 ACK: your new IP /10.252.132.159, netmask /255.255.240.0, gateways [/10.252.143.254] DNS servers: /10.252.143.254 , lease time 7200
2017-06-12 11:51:12.001	DEBUG:	DhcpClient : Confirmed lease: IP address 10.252.132.159/20 Gateway 10.252.143.254  DNS servers: [ 10.252.143.254 ] Domains localdomain DHCP server /10.252.143.254 Vendor info null lease 7200 seconds
2017-06-12 11:51:12.005	DEBUG:	WifiStateMachine : updateCapabilities for config:TestObject Devicesfalse,false
2017-06-12 11:51:12.005	DEBUG:	CommandListener : Setting iface cfg
2017-06-12 11:51:12.016	DEBUG:	WifiStateMachine : updateCapabilities for config:TestObject Devicesfalse,false
2017-06-12 11:51:12.016	DEBUG:	DhcpClient : Scheduling renewal in 3599s
2017-06-12 11:51:12.016	DEBUG:	DhcpClient : Scheduling rebind in 6299s
2017-06-12 11:51:12.016	DEBUG:	DhcpClient : Scheduling expiry in 7199s
2017-06-12 11:51:12.017	ERROR:	WifiNative-HAL : setBssidBlacklist cmd 3 size 0
2017-06-12 11:51:12.017	DEBUG:	wifi : configure BSSID black list request [4] = 0x7a75ce79e0
2017-06-12 11:51:12.017	DEBUG:	wifi : Added 0 bssids
2017-06-12 11:51:12.018	DEBUG:	ConnectivityService : NetworkAgentInfo [WIFI () - 103] EVENT_NETWORK_INFO_CHANGED, going from CONNECTING to CONNECTED
2017-06-12 11:51:12.020	DEBUG:	WifiStateMachine : updateCapabilities for config:TestObject Devicesfalse,false
2017-06-12 11:51:12.021	DEBUG:	ConnectivityService : Adding iface wlan0 to network 103
2017-06-12 11:51:12.032	ERROR:	WifiStateMachine : Did not find remoteAddress {10.252.143.254} in /proc/net/arp
2017-06-12 11:51:12.074	DEBUG:	ConnectivityService : Setting DNS servers for network 103 to [/10.252.143.254]
2017-06-12 11:51:12.093	DEBUG:	WifiNetworkAgent : NetworkAgent: Received signal strength thresholds: []
2017-06-12 11:51:12.093	DEBUG:	WifiNative-HAL : stopRssiMonitoring, cmdId 0
2017-06-12 11:51:12.094	DEBUG:	ConnectivityService : Switching to new default network: NetworkAgentInfo{ ni{[type: WIFI[], state: CONNECTED/CONNECTED, reason: (unspecified), extra: "TestObject Devices", failover: false, available: true, roaming: false, metered: false]}  network{103}  nethandle{442398067422}  lp{{InterfaceName: wlan0 LinkAddresses: [10.252.132.159/20,]  Routes: [fe80::/64 -> :: wlan0,10.252.128.0/20 -> 0.0.0.0 wlan0,0.0.0.0/0 -> 10.252.143.254 wlan0,] DnsAddresses: [10.252.143.254,] Domains: localdomain MTU: 0 TcpBufferSizes: 524288,6291456,8291456,524288,6291456,8291456}}  nc{[ Transports: WIFI Capabilities: NOT_METERED&INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&FOREGROUND LinkUpBandwidth>=1048576Kbps LinkDnBandwidth>=1048576Kbps SignalStrength: -31]}  Score{20}  everValidated{false}  lastValidated{false}  created{true} lingering{false} explicitlySelected{false} acceptUnvalidated{false} everCaptivePortalDetected{false} lastCaptivePortalDetected{false} }
2017-06-12 11:51:12.109	DEBUG:	NetworkMonitor/NetworkAgentInfo [WIFI () - 103] : PROBE_DNS OK 12ms, connectivitycheck.gstatic.com=216.58.208.35
2017-06-12 11:51:12.110	DEBUG:	NetworkMonitor/NetworkAgentInfo [WIFI () - 103] : PROBE_DNS OK 11ms, www.google.com=172.217.18.4
2017-06-12 11:51:12.153	DEBUG:	NetworkMonitor/NetworkAgentInfo [WIFI () - 103] : PROBE_HTTP http://connectivitycheck.gstatic.com/generate_204 time=36ms ret=204 headers={null=[HTTP/1.1 204 No Content], Content-Length=[0], Date=[Mon, 12 Jun 2017 07:51:12 GMT], X-Android-Received-Millis=[1497253872148], X-Android-Response-Source=[NETWORK 204], X-Android-Selected-Protocol=[http/1.1], X-Android-Sent-Millis=[1497253872133]}
2017-06-12 11:51:12.177	INFO:	WifiHAL : Fate Tx-Rx: Packet fate stats stop received
2017-06-12 11:51:12.182	WARN:	QCNEJ : |CORE| network available: 103
2017-06-12 11:51:12.183	DEBUG:	ConnectivityService : Sending CONNECTED broadcast for type 1 NetworkAgentInfo [WIFI () - 103] isDefaultNetwork=true
2017-06-12 11:51:12.188	WARN:	QCNEJ : |CORE| onAvailable: bind the process to WIFI
2017-06-12 11:51:12.189	WARN:	QCNEJ : |CORE| newLp: {InterfaceName: wlan0 LinkAddresses: [10.252.132.159/20,fe80::7af8:82ff:fe9e:e9a4/64,]  Routes: [fe80::/64 -> :: wlan0,10.252.128.0/20 -> 0.0.0.0 wlan0,0.0.0.0/0 -> 10.252.143.254 wlan0,] DnsAddresses: [10.252.143.254,] Domains: localdomain MTU: 0 TcpBufferSizes: 524288,6291456,8291456,524288,6291456,8291456}
2017-06-12 11:51:12.189	WARN:	QCNEJ : |CORE| curLp: {InterfaceName: wlan0 LinkAddresses: [10.252.132.159/20,fe80::7af8:82ff:fe9e:e9a4/64,]  Routes: [fe80::/64 -> :: wlan0,10.252.128.0/20 -> 0.0.0.0 wlan0,0.0.0.0/0 -> 10.252.143.254 wlan0,] DnsAddresses: [10.252.143.254,] Domains: localdomain MTU: 0}
2017-06-12 11:51:12.197	INFO:	Adreno : QUALCOMM build                   : 6818200, Idb2b4cb785
2017-06-12 11:51:12.197	INFO:	Adreno : Build Date                       : 11/18/16
2017-06-12 11:51:12.197	INFO:	Adreno : OpenGL ES Shader Compiler Version: XE031.09.00.04
2017-06-12 11:51:12.197	INFO:	Adreno : Local Branch                     : N25
2017-06-12 11:51:12.197	INFO:	Adreno : Remote Branch                    :
2017-06-12 11:51:12.197	INFO:	Adreno : Remote Branch                    :
2017-06-12 11:51:12.197	INFO:	Adreno : Reconstruct Branch               :
2017-06-12 11:51:12.202	DEBUG:	MusicLifecycle : com.google.android.music.net.NetworkConnectivityMonitor$NetworkChangedReceiver generated event: Broadcast received with context com.google.android.music.ui.PhoneMusicApplication@a7c68f1 and intent Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4000010 (has extras) }
2017-06-12 11:51:12.203	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253958968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:12.203	INFO:	DEVICE MANAGER : {"id":"1497253958968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:12.204	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253958968","orientation":"PORTRAIT"}'
2017-06-12 11:51:12.214	DEBUG:	BugleThrottledAction : CountryCodeDetectorAction already scheduled in 38982ms, not scheduling it again.
2017-06-12 11:51:12.218	DEBUG:	RcsService : Never provisioned and provisioning is not allowed, skipped config update request
2017-06-12 11:51:12.217	INFO:	NetworkConnectivity : Network state changed: [type: WIFI[], state: CONNECTED/CONNECTED, reason: (unspecified), extra: "TestObject Devices", failover: false, available: true, roaming: false, metered: false]
2017-06-12 11:51:12.222	DEBUG:	NetworkMonitor/NetworkAgentInfo [WIFI () - 103] : PROBE_HTTPS https://www.google.com/generate_204 time=110ms ret=204 headers={null=[HTTP/1.1 204 No Content], Alt-Svc=[quic=":443"; ma=2592000; v="38,37,36,35"], Content-Length=[0], Date=[Mon, 12 Jun 2017 07:51:12 GMT], X-Android-Received-Millis=[1497253872221], X-Android-Response-Source=[NETWORK 204], X-Android-Selected-Protocol=[http/1.1], X-Android-Sent-Millis=[1497253872148]}
2017-06-12 11:51:12.223	DEBUG:	ConnectivityService : NetworkAgentInfo [WIFI () - 103] validation passed
2017-06-12 11:51:12.231	INFO:	NetworkPolicyMonitor : Download-ability status changed to (true) unmetered wifi/eth: true mobileOrMetered: false
2017-06-12 11:51:12.234	INFO:	OpenGLRenderer : Initialized EGL, version 1.4
2017-06-12 11:51:12.234	DEBUG:	OpenGLRenderer : Swap behavior 1
2017-06-12 11:51:12.237	DEBUG:	WifiNetworkHistory : saving network history: "TestObject Devices"WPA_PSK gw: null Network Selection-status: NETWORK_SELECTION_ENABLED ephemeral=false choice:null link:0 status:0 nid:0 hasEverConnected: true
2017-06-12 11:51:12.240	INFO:	NetworkPolicyMonitor : Stream-ability status changed to (true) unmetered wifi/eth: true mobileOrMetered: false
2017-06-12 11:51:12.398	INFO:	ActivityManager : Displayed org.test.myapp/org.kivy.android.PythonActivity: +550ms
2017-06-12 11:51:12.456	INFO:	PBSessionCacheImpl : Deleted sessionId[68803168747701] from persistence.
2017-06-12 11:51:12.493	INFO:	DeviceStateChecker : DeviceStateChecker cancelled
2017-06-12 11:51:12.494	INFO:	MicroDetector : Keeping mic open: false
2017-06-12 11:51:12.543	INFO:	MicroRecognitionRunner : Stopping hotword detection.
2017-06-12 11:51:12.543	INFO:	AudioController : internalShutdown
2017-06-12 11:51:12.544	INFO:	MicrophoneInputStream : mic_close com.google.android.apps.gsa.speech.audio.af@f52928
2017-06-12 11:51:12.591	DEBUG:	audio_hw_primary : disable_audio_route: usecase(8) reset and update mixer path: audio-record
2017-06-12 11:51:12.592	DEBUG:	audio_hw_primary : disable_snd_device: snd_device(63: voice-rec-mic)
2017-06-12 11:51:12.596	DEBUG:	sound_trigger_platform : platform_stdev_check_and_update_concurrency: concurrency active 0, tx 0, rx 0, concurrency session_allowed 1
2017-06-12 11:51:12.597	INFO:	SoundTriggerHwService::Module : void android::SoundTriggerHwService::Module::onCallbackEvent(const sp<android::SoundTriggerHwService::CallbackEvent> &) mClient == 0
2017-06-12 11:51:12.599	INFO:	MicroRecognitionRunner : Detection finished
2017-06-12 11:51:12.675	DEBUG:	GeckoPushGCM : Message received.  Processing on background thread.
2017-06-12 11:51:12.676	INFO:	GeckoPushService : Google Play Services GCM message received; delivering.
2017-06-12 11:51:12.676	WARN:	GeckoPushService : No chid found; ignoring message.
2017-06-12 11:51:12.704	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253959468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:12.704	INFO:	DEVICE MANAGER : {"id":"1497253959468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:12.706	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253959468","orientation":"PORTRAIT"}'
2017-06-12 11:51:12.789	INFO:	wpa_supplicant : TDLS: Invalid frame - payloadtype=1 category=240 action=10
2017-06-12 11:51:12.859	INFO:	Icing : Indexing 3E6BC02FD171012F08D51FB532CD7396824CE96F from com.google.android.gms
2017-06-12 11:51:12.911	INFO:	Icing : Indexing done 3E6BC02FD171012F08D51FB532CD7396824CE96F
2017-06-12 11:51:13.204	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253959968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:13.204	INFO:	DEVICE MANAGER : {"id":"1497253959968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:13.205	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253959968","orientation":"PORTRAIT"}'
2017-06-12 11:51:13.415	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:13.443	INFO:	art : Explicit concurrent mark sweep GC freed 557(67KB) AllocSpace objects, 2(40KB) LOS objects, 39% free, 18MB/30MB, paused 263us total 27.290ms
2017-06-12 11:51:13.594	WARN:	linker : /data/app/org.test.myapp-1/lib/arm/libpython2.7.so: is missing DT_SONAME will use basename as a replacement: "libpython2.7.so"
2017-06-12 11:51:13.617	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/lib-dynload/_io.so: is missing DT_SONAME will use basename as a replacement: "_io.so"
2017-06-12 11:51:13.618	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/lib-dynload/unicodedata.so: is missing DT_SONAME will use basename as a replacement: "unicodedata.so"
2017-06-12 11:51:13.619	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/lib-dynload/_ctypes.so: is missing DT_SONAME will use basename as a replacement: "_ctypes.so"
2017-06-12 11:51:13.649	INFO:	PythonActivity : Surface will NOT be transparent
2017-06-12 11:51:13.704	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253960468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:13.704	INFO:	DEVICE MANAGER : {"id":"1497253960468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:13.704	INFO:	sensors : batch
2017-06-12 11:51:13.706	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253960468","orientation":"PORTRAIT"}'
2017-06-12 11:51:13.708	INFO:	nanohub : queueBatch: sensor=1, handle=1, period=20000000, latency=0
2017-06-12 11:51:13.708	INFO:	sensors : activate
2017-06-12 11:51:13.709	INFO:	nanohub : queueActivate: sensor=1, handle=1, enable=1
2017-06-12 11:51:13.711	INFO:	nanohub : osLog: [BMI160] accSetRate: rate=51200, latency=19999744, state=3
2017-06-12 11:51:13.715	INFO:	SDL : SDL_Android_Init()
2017-06-12 11:51:13.715	INFO:	SDL : SDL_Android_Init() finished!
2017-06-12 11:51:13.715	INFO:	python : Initialize Python for Android
2017-06-12 11:51:13.715	INFO:	python : Changing directory to the one provided by ANDROID_ARGUMENT
2017-06-12 11:51:13.715	INFO:	python : /data/user/0/org.test.myapp/files/app
2017-06-12 11:51:13.715	INFO:	python : Preparing to initialize python
2017-06-12 11:51:13.715	INFO:	python : crystax_python does not exist
2017-06-12 11:51:13.722	INFO:	python : Initialized python
2017-06-12 11:51:13.722	INFO:	python : AND: Init threads
2017-06-12 11:51:13.724	INFO:	python : testing python print redirection
2017-06-12 11:51:13.725	INFO:	python : Setting up python from ANDROID_PRIVATE
2017-06-12 11:51:13.726	INFO:	python : ('Android path', ['/data/user/0/org.test.myapp/files/app/lib/python27.zip', '/data/user/0/org.test.myapp/files/app/lib/python2.7/', '/data/user/0/org.test.myapp/files/app/lib/python2.7/lib-dynload/', '/data/user/0/org.test.myapp/files/app/lib/python2.7/site-packages/', '/data/user/0/org.test.myapp/files/app'])
2017-06-12 11:51:13.741	INFO:	python : ('os.environ is', {'DOWNLOAD_CACHE': '/data/cache', 'EXTERNAL_STORAGE': '/sdcard', 'ANDROID_ENTRYPOINT': 'main.pyo', 'ANDROID_ASSETS': '/system/app', 'PYTHONPATH': '/data/user/0/org.test.myapp/files/app:/data/user/0/org.test.myapp/files/app/lib', 'ANDROID_APP_PATH': '/data/user/0/org.test.myapp/files/app', 'ANDROID_ROOT': '/system', 'SYSTEMSERVERCLASSPATH': '/system/framework/services.jar:/system/framework/ethernet-service.jar:/system/framework/wifi-service.jar', 'PYTHONOPTIMIZE': '2', 'ANDROID_DATA': '/data', 'PYTHONHOME': '/data/user/0/org.test.myapp/files/app', 'ANDROID_ARGUMENT': '/data/user/0/org.test.myapp/files/app', 'BOOTCLASSPATH': '/system/framework/core-oj.jar:/system/framework/core-libart.jar:/system/framework/conscrypt.jar:/system/framework/okhttp.jar:/system/framework/core-junit.jar:/system/framework/bouncycastle.jar:/system/framework/ext.jar:/system/framework/framework.jar:/system/framework/telephony-common.jar:/system/framework/voip-common.jar:/system/framework/ims-common.jar:/system/framework/apache-xml.jar:/system/framework/org.apache.http.legacy.boot.jar', 'ANDROID_SOCKET_zygote_secondary': '9', 'ASEC_MOUNTPOINT': '/mnt/asec', 'PATH': '/sbin:/vendor/bin:/system/sbin:/system/bin:/system/xbin', 'ANDROID_STORAGE': '/storage', 'ANDROID_BOOTLOGO': '1', 'ANDROID_PRIVATE': '/data/user/0/org.test.myapp/files', 'PYTHON_NAME': 'python'})
2017-06-12 11:51:13.741	INFO:	python : ('Android kivy bootstrap done. __name__ is', '__main__')
2017-06-12 11:51:13.767	INFO:	python : ['/data/user/0/org.test.myapp/files/app/lib/python2.7/site-packages', '/data/user/0/org.test.myapp/files/app/lib/site-python']
2017-06-12 11:51:13.767	INFO:	python : AND: Ran string
2017-06-12 11:51:13.767	INFO:	python : Run user program, change dir and execute entrypoint
2017-06-12 11:51:13.836	INFO:	python : [WARNING] [Config      ] Older configuration version detected (0 instead of 19)
2017-06-12 11:51:13.837	INFO:	python : [WARNING] [Config      ] Upgrading configuration in progress.
2017-06-12 11:51:13.842	INFO:	python : [INFO   ] [Logger      ] Record log in /data/user/0/org.test.myapp/files/app/.kivy/logs/kivy_17-06-12_0.txt
2017-06-12 11:51:13.842	INFO:	python : [INFO   ] [Kivy        ] v1.10.0
2017-06-12 11:51:13.842	INFO:	python : [INFO   ] [Python      ] v2.7.2 (default, Jun 10 2017, 12:12:30)
2017-06-12 11:51:13.843	INFO:	python : [GCC 4.8]
2017-06-12 11:51:13.847	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/_clock.so: is missing DT_SONAME will use basename as a replacement: "_clock.so"
2017-06-12 11:51:13.858	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/_event.so: is missing DT_SONAME will use basename as a replacement: "_event.so"
2017-06-12 11:51:13.859	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/properties.so: is missing DT_SONAME will use basename as a replacement: "properties.so"
2017-06-12 11:51:13.866	INFO:	python : [INFO   ] [Factory     ] 194 symbols loaded
2017-06-12 11:51:14.125	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/instructions.so: is missing DT_SONAME will use basename as a replacement: "instructions.so"
2017-06-12 11:51:14.128	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/buffer.so: is missing DT_SONAME will use basename as a replacement: "buffer.so"
2017-06-12 11:51:14.129	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/vertex.so: is missing DT_SONAME will use basename as a replacement: "vertex.so"
2017-06-12 11:51:14.130	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/cgl.so: is missing DT_SONAME will use basename as a replacement: "cgl.so"
2017-06-12 11:51:14.132	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/vbo.so: is missing DT_SONAME will use basename as a replacement: "vbo.so"
2017-06-12 11:51:14.133	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/compiler.so: is missing DT_SONAME will use basename as a replacement: "compiler.so"
2017-06-12 11:51:14.134	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/transformation.so: is missing DT_SONAME will use basename as a replacement: "transformation.so"
2017-06-12 11:51:14.135	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/shader.so: is missing DT_SONAME will use basename as a replacement: "shader.so"
2017-06-12 11:51:14.136	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/texture.so: is missing DT_SONAME will use basename as a replacement: "texture.so"
2017-06-12 11:51:14.137	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/context_instructions.so: is missing DT_SONAME will use basename as a replacement: "context_instructions.so"
2017-06-12 11:51:14.161	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/core/image/_img_sdl2.so: is missing DT_SONAME will use basename as a replacement: "_img_sdl2.so"
2017-06-12 11:51:14.165	INFO:	python : [INFO   ] [Image       ] Providers: img_tex, img_dds, img_sdl2, img_gif (img_pil, img_ffpyplayer ignored)
2017-06-12 11:51:14.167	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/fbo.so: is missing DT_SONAME will use basename as a replacement: "fbo.so"
2017-06-12 11:51:14.168	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/context.so: is missing DT_SONAME will use basename as a replacement: "context.so"
2017-06-12 11:51:14.169	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/opengl.so: is missing DT_SONAME will use basename as a replacement: "opengl.so"
2017-06-12 11:51:14.177	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/opengl_utils.so: is missing DT_SONAME will use basename as a replacement: "opengl_utils.so"
2017-06-12 11:51:14.179	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/vertex_instructions.so: is missing DT_SONAME will use basename as a replacement: "vertex_instructions.so"
2017-06-12 11:51:14.181	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/stencil_instructions.so: is missing DT_SONAME will use basename as a replacement: "stencil_instructions.so"
2017-06-12 11:51:14.183	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/gl_instructions.so: is missing DT_SONAME will use basename as a replacement: "gl_instructions.so"
2017-06-12 11:51:14.184	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/scissor_instructions.so: is missing DT_SONAME will use basename as a replacement: "scissor_instructions.so"
2017-06-12 11:51:14.185	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/weakproxy.so: is missing DT_SONAME will use basename as a replacement: "weakproxy.so"
2017-06-12 11:51:14.206	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253960968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:14.206	INFO:	DEVICE MANAGER : {"id":"1497253960968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:14.209	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253960968","orientation":"PORTRAIT"}'
2017-06-12 11:51:14.214	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/core/window/_window_sdl2.so: is missing DT_SONAME will use basename as a replacement: "_window_sdl2.so"
2017-06-12 11:51:14.227	INFO:	python : [INFO   ] [OSC         ] using <thread> for socket
2017-06-12 11:51:14.230	INFO:	python : [INFO   ] [Window      ] Provider: sdl2
2017-06-12 11:51:14.247	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/cgl_backend/cgl_glew.so: is missing DT_SONAME will use basename as a replacement: "cgl_glew.so"
2017-06-12 11:51:14.248	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/cgl_backend/cgl_gl.so: is missing DT_SONAME will use basename as a replacement: "cgl_gl.so"
2017-06-12 11:51:14.262	INFO:	python : [INFO   ] [GL          ] Using the "OpenGL ES 2" graphics system
2017-06-12 11:51:14.263	INFO:	python : [INFO   ] [GL          ] Backend used <gl>
2017-06-12 11:51:14.263	INFO:	python : [INFO   ] [GL          ] OpenGL version <OpenGL ES 3.2 [email protected] (GIT@Idb2b4cb785)>
2017-06-12 11:51:14.263	INFO:	python : [INFO   ] [GL          ] OpenGL vendor <Qualcomm>
2017-06-12 11:51:14.263	INFO:	python : [INFO   ] [GL          ] OpenGL renderer <Adreno (TM) 418>
2017-06-12 11:51:14.264	INFO:	python : [INFO   ] [GL          ] OpenGL parsed version: 3, 2
2017-06-12 11:51:14.264	INFO:	python : [INFO   ] [GL          ] Texture max size <16384>
2017-06-12 11:51:14.264	INFO:	python : [INFO   ] [GL          ] Texture max units <16>
2017-06-12 11:51:14.301	INFO:	python : [INFO   ] [Window      ] auto add sdl2 input provider
2017-06-12 11:51:14.302	INFO:	python : [INFO   ] [Window      ] virtual keyboard not allowed, single mode, not docked
2017-06-12 11:51:14.303	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/memory_handlers/block.so: is missing DT_SONAME will use basename as a replacement: "block.so"
2017-06-12 11:51:14.304	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/memory_handlers/membuffer.so: is missing DT_SONAME will use basename as a replacement: "membuffer.so"
2017-06-12 11:51:14.305	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/memory_handlers/utils.so: is missing DT_SONAME will use basename as a replacement: "utils.so"
2017-06-12 11:51:14.306	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/memory_handlers/pool.so: is missing DT_SONAME will use basename as a replacement: "pool.so"
2017-06-12 11:51:14.306	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/memory_handlers/zone.so: is missing DT_SONAME will use basename as a replacement: "zone.so"
2017-06-12 11:51:14.307	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/memory_handlers/indexing.so: is missing DT_SONAME will use basename as a replacement: "indexing.so"
2017-06-12 11:51:14.308	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/memory_handlers/tests.so: is missing DT_SONAME will use basename as a replacement: "tests.so"
2017-06-12 11:51:14.309	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/vertex_format.so: is missing DT_SONAME will use basename as a replacement: "vertex_format.so"
2017-06-12 11:51:14.310	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/gl_debug.so: is missing DT_SONAME will use basename as a replacement: "gl_debug.so"
2017-06-12 11:51:14.311	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/frame_objects.so: is missing DT_SONAME will use basename as a replacement: "frame_objects.so"
2017-06-12 11:51:14.312	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/fixedvbo.so: is missing DT_SONAME will use basename as a replacement: "fixedvbo.so"
2017-06-12 11:51:14.313	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/cmesh.so: is missing DT_SONAME will use basename as a replacement: "cmesh.so"
2017-06-12 11:51:14.315	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/uix/cwidget.so: is missing DT_SONAME will use basename as a replacement: "cwidget.so"
2017-06-12 11:51:14.317	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/uix/gamescreens.so: is missing DT_SONAME will use basename as a replacement: "gamescreens.so"
2017-06-12 11:51:14.323	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/systems/gamesystem.so: is missing DT_SONAME will use basename as a replacement: "gamesystem.so"
2017-06-12 11:51:14.325	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/managers/resource_managers.so: is missing DT_SONAME will use basename as a replacement: "resource_managers.so"
2017-06-12 11:51:14.326	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/managers/game_manager.so: is missing DT_SONAME will use basename as a replacement: "game_manager.so"
2017-06-12 11:51:14.327	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/vertex_formats.so: is missing DT_SONAME will use basename as a replacement: "vertex_formats.so"
2017-06-12 11:51:14.328	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/model.so: is missing DT_SONAME will use basename as a replacement: "model.so"
2017-06-12 11:51:14.329	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/svg_loader.so: is missing DT_SONAME will use basename as a replacement: "svg_loader.so"
2017-06-12 11:51:14.330	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/graphics/tesselator.so: is missing DT_SONAME will use basename as a replacement: "tesselator.so"
2017-06-12 11:51:14.346	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/managers/entity_manager.so: is missing DT_SONAME will use basename as a replacement: "entity_manager.so"
2017-06-12 11:51:14.347	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/memory_handlers/zonedblock.so: is missing DT_SONAME will use basename as a replacement: "zonedblock.so"
2017-06-12 11:51:14.348	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/systems/staticmemgamesystem.so: is missing DT_SONAME will use basename as a replacement: "staticmemgamesystem.so"
2017-06-12 11:51:14.349	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/managers/system_manager.so: is missing DT_SONAME will use basename as a replacement: "system_manager.so"
2017-06-12 11:51:14.350	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/entity.so: is missing DT_SONAME will use basename as a replacement: "entity.so"
2017-06-12 11:51:14.351	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/managers/sound_manager.so: is missing DT_SONAME will use basename as a replacement: "sound_manager.so"
2017-06-12 11:51:14.354	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/core/audio/audio_sdl2.so: is missing DT_SONAME will use basename as a replacement: "audio_sdl2.so"
2017-06-12 11:51:14.356	INFO:	python : [INFO   ] [Audio       ] Providers: audio_sdl2 (audio_ffpyplayer ignored)
2017-06-12 11:51:14.357	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/gameworld.so: is missing DT_SONAME will use basename as a replacement: "gameworld.so"
2017-06-12 11:51:14.358	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/systems/position_systems.so: is missing DT_SONAME will use basename as a replacement: "position_systems.so"
2017-06-12 11:51:14.359	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/managers/animation_manager.so: is missing DT_SONAME will use basename as a replacement: "animation_manager.so"
2017-06-12 11:51:14.360	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/animation.so: is missing DT_SONAME will use basename as a replacement: "animation.so"
2017-06-12 11:51:14.362	INFO:	python : [INFO   ] KURWA6
2017-06-12 11:51:14.363	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/systems/scale_systems.so: is missing DT_SONAME will use basename as a replacement: "scale_systems.so"
2017-06-12 11:51:14.364	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/systems/gameview.so: is missing DT_SONAME will use basename as a replacement: "gameview.so"
2017-06-12 11:51:14.366	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/systems/rotate_systems.so: is missing DT_SONAME will use basename as a replacement: "rotate_systems.so"
2017-06-12 11:51:14.367	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/systems/color_systems.so: is missing DT_SONAME will use basename as a replacement: "color_systems.so"
2017-06-12 11:51:14.368	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/systems/gamemap.so: is missing DT_SONAME will use basename as a replacement: "gamemap.so"
2017-06-12 11:51:14.369	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/systems/renderers.so: is missing DT_SONAME will use basename as a replacement: "renderers.so"
2017-06-12 11:51:14.370	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/batching.so: is missing DT_SONAME will use basename as a replacement: "batching.so"
2017-06-12 11:51:14.372	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/systems/lifespan.so: is missing DT_SONAME will use basename as a replacement: "lifespan.so"
2017-06-12 11:51:14.373	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/systems/animation.so: is missing DT_SONAME will use basename as a replacement: "animation.so"
2017-06-12 11:51:14.376	INFO:	python : [DEBUG  ] [App         ] Loading kv <./yourappname.kv>
2017-06-12 11:51:14.398	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/core/text/text_layout.so: is missing DT_SONAME will use basename as a replacement: "text_layout.so"
2017-06-12 11:51:14.400	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/core/text/_text_sdl2.so: is missing DT_SONAME will use basename as a replacement: "_text_sdl2.so"
2017-06-12 11:51:14.402	INFO:	python : [INFO   ] [Text        ] Provider: sdl2
2017-06-12 11:51:14.407	WARN:	linker : /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/jnius/jnius.so: is missing DT_SONAME will use basename as a replacement: "jnius.so"
2017-06-12 11:51:14.704	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253961468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:14.704	INFO:	DEVICE MANAGER : {"id":"1497253961468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:14.706	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253961468","orientation":"PORTRAIT"}'
2017-06-12 11:51:14.736	INFO:	python : [DEBUG  ] [Resource    ] add </system/fonts> in path list
2017-06-12 11:51:14.738	INFO:	python : [DEBUG  ] [Resource    ] add </data/user/0/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/data/fonts> in path list
2017-06-12 11:51:14.750	INFO:	python : [INFO   ] [Shader      ] Read <poscolorshader.glsl>
2017-06-12 11:51:14.756	INFO:	python : [DEBUG  ] [Shader      ] Vertex compiled successfully
2017-06-12 11:51:14.760	INFO:	python : [DEBUG  ] [Shader      ] Fragment compiled successfully
2017-06-12 11:51:14.772	INFO:	python : [ERROR  ] [GameSystem  ] System_id: position not attached retrying in 1 sec. If you see this error once or twice, we are probably just waiting on the KV file to load. If you see it a whole bunch something is probably wrong. Make sure all systems are setup properly.
2017-06-12 11:51:14.774	INFO:	python : [DEBUG  ] [Base        ] Create provider from android
2017-06-12 11:51:14.774	INFO:	python : [WARNING] [Base        ] Unknown <android> provider
2017-06-12 11:51:14.775	INFO:	python : [INFO   ] [Base        ] Start application main loop
2017-06-12 11:51:14.780	INFO:	python : [INFO   ] [GL          ] NPOT texture support is available
2017-06-12 11:51:14.782	INFO:	python : [ERROR  ] [Base        ] Failed to import "android" module. Could not remove android presplash.
2017-06-12 11:51:14.784	INFO:	python : [DEBUG  ] [Atlas       ] Load </data/user/0/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/data/images/defaulttheme.atlas>
2017-06-12 11:51:14.789	INFO:	python : [DEBUG  ] [Atlas       ] Need to load 1 images
2017-06-12 11:51:14.790	INFO:	python : [DEBUG  ] [Atlas       ] Load </data/user/0/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/data/images/defaulttheme-0.png>
2017-06-12 11:51:14.791	INFO:	python : [DEBUG  ] [ImageSDL2   ] Load </data/user/0/org.test.myapp/files/app/lib/python2.7/site-packages/kivy/data/images/defaulttheme-0.png>
2017-06-12 11:51:14.917	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:14.931	INFO:	art : Explicit concurrent mark sweep GC freed 104(4KB) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 191us total 13.204ms
2017-06-12 11:51:15.203	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253961968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:15.203	INFO:	DEVICE MANAGER : {"id":"1497253961968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:15.204	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253961968","orientation":"PORTRAIT"}'
2017-06-12 11:51:15.704	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253962468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:15.704	INFO:	DEVICE MANAGER : {"id":"1497253962468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:15.706	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253962468","orientation":"PORTRAIT"}'
2017-06-12 11:51:16.206	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253962968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:16.206	INFO:	DEVICE MANAGER : {"id":"1497253962968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:16.210	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253962968","orientation":"PORTRAIT"}'
2017-06-12 11:51:16.419	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:16.475	INFO:	art : Explicit concurrent mark sweep GC freed 38(2112B) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 277us total 55.353ms
2017-06-12 11:51:16.706	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253963468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:16.706	INFO:	DEVICE MANAGER : {"id":"1497253963468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:16.709	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253963468","orientation":"PORTRAIT"}'
2017-06-12 11:51:17.187	INFO:	python : [INFO   ] [KivEnt      ] Vertex Format: vertex_format_4f4ub registered. Size per vertex is: 20. Format is [('pos', 2, 'float', 0, False), ('uvs', 2, 'float', 8, False), ('v_color', 4, 'ubyte', 16, True)].
2017-06-12 11:51:17.188	INFO:	python : [INFO   ] [KivEnt      ] Vertex Format: vertex_format_4f registered. Size per vertex is: 16. Format is [('pos', 2, 'float', 0, False), ('uvs', 2, 'float', 8, False)].
2017-06-12 11:51:17.188	INFO:	python : [INFO   ] [KivEnt      ] Vertex Format: vertex_format_2f4ub registered. Size per vertex is: 12. Format is [('pos', 2, 'float', 0, False), ('v_color', 4, 'ubyte', 8, True)].
2017-06-12 11:51:17.188	INFO:	python : [INFO   ] [KivEnt      ] Vertex Format: vertex_format_5f4ub registered. Size per vertex is: 24. Format is [('pos', 2, 'float', 0, False), ('rot', 1, 'float', 8, False), ('center', 2, 'float', 12, False), ('v_color', 4, 'ubyte', 20, True)].
2017-06-12 11:51:17.189	INFO:	python : [INFO   ] [KivEnt      ] Vertex Format: vertex_format_7f registered. Size per vertex is: 28. Format is [('pos', 2, 'float', 0, False), ('uvs', 2, 'float', 8, False), ('rot', 1, 'float', 16, False), ('center', 2, 'float', 20, False)].
2017-06-12 11:51:17.189	INFO:	python : [INFO   ] [KivEnt      ] Vertex Format: vertex_format_7f4ub registered. Size per vertex is: 32. Format is [('pos', 2, 'float', 0, False), ('uvs', 2, 'float', 8, False), ('rot', 1, 'float', 16, False), ('center', 2, 'float', 20, False), ('v_color', 4, 'ubyte', 28, True)].
2017-06-12 11:51:17.189	INFO:	python : [INFO   ] [KivEnt      ] Model Manager reserved space for vertex format: vertex_format_2f4ub. 200 KiB was reserved for vertices, fitting a total of 17066. 200 KiB was reserved for indices fitting a total of 102400.
2017-06-12 11:51:17.206	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253963968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:17.206	INFO:	DEVICE MANAGER : {"id":"1497253963968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:17.210	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253963968","orientation":"PORTRAIT"}'
2017-06-12 11:51:17.487	INFO:	python : [INFO   ] [KivEnt      ] position allocated 7680 KiB
2017-06-12 11:51:17.611	INFO:	art : Waiting for a blocking GC DisableMovingGc
2017-06-12 11:51:17.612	INFO:	art : Waiting for a blocking GC DisableMovingGc
2017-06-12 11:51:17.613	INFO:	art : Starting a blocking GC DisableMovingGc
2017-06-12 11:51:17.619	INFO:	art : WaitForGcToComplete blocked for 6.645ms for cause DisableMovingGc
2017-06-12 11:51:17.619	INFO:	art : Starting a blocking GC DisableMovingGc
2017-06-12 11:51:17.680	INFO:	PlaceInferenceEngine : [anon] Changed inference mode: 105
2017-06-12 11:51:17.703	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253964468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:17.703	INFO:	DEVICE MANAGER : {"id":"1497253964468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:17.705	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253964468","orientation":"PORTRAIT"}'
2017-06-12 11:51:17.831	INFO:	python : [INFO   ] [KivEnt      ] Batches for canvas: <kivy.graphics.instructions.RenderContext object at 0xcd707648> will have 21845 verts and 131072 indices.VBO will be 256 in KiB per frame with 20 total vbos, an estimated 5461 enities fit in each batch with 4 verts per entity
2017-06-12 11:51:17.832	INFO:	python : [INFO   ] [KivEnt      ] poly_renderer allocated 30304 KiB
2017-06-12 11:51:17.832	INFO:	python : [INFO   ] [KivEnt      ] We will need 60026 KiB for game, we have 614400 KiB
2017-06-12 11:51:17.834	INFO:	python : [DEBUG  ] in _batch_entity model._vertex_count=3 model._index_count=3
2017-06-12 11:51:17.834	INFO:	python : [DEBUG  ] vbo_size=256
2017-06-12 11:51:17.835	INFO:	python : [DEBUG  ] set index_vbo.data_size to 0
2017-06-12 11:51:17.835	INFO:	python : [DEBUG  ] batch add_entity num_indices=3 num_verts=3
2017-06-12 11:51:17.835	INFO:	python : [DEBUG  ] [KivEnt      ] Entity: 0 batched at vertex#: 0 indices#: 0
2017-06-12 11:51:17.835	INFO:	python : [DEBUG  ] [KivEnt      ] Entity 0 created with components: position: 0, poly_renderer: 0,
2017-06-12 11:51:17.841	INFO:	python : [DEBUG  ] self.current_frame=1 self.frame_count=1
2017-06-12 11:51:17.841	INFO:	python : [DEBUG  ] will bind vertices
2017-06-12 11:51:17.842	INFO:	python : [DEBUG  ] glBufferData(target=34962 data_size=262144L usage=35040) (will dump first 300)
2017-06-12 11:51:17.842	INFO:	python : 00000000: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.842	INFO:	python : 00000010: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.842	INFO:	python : 00000020: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.842	INFO:	python : 00000030: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.842	INFO:	python : 00000040: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.842	INFO:	python : 00000050: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.842	INFO:	python : 00000060: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.842	INFO:	python : 00000070: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.842	INFO:	python : 00000080: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.842	INFO:	python : 00000090: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.842	INFO:	python : 000000A0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.842	INFO:	python : 000000B0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.843	INFO:	python : 000000C0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.843	INFO:	python : 000000D0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.843	INFO:	python : 000000E0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.843	INFO:	python : 000000F0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.843	INFO:	python : 00000100: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.843	INFO:	python : 00000110: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:17.843	INFO:	python : 00000120: 00 00 00 00 00 00 00 00  00 00 00 00              ............
2017-06-12 11:51:17.844	INFO:	python : [DEBUG  ] glVertexAttribPointer(1, 2, 5126, 0, 12, 0)
2017-06-12 11:51:17.844	INFO:	python : [DEBUG  ] glVertexAttribPointer(0, 4, 5121, 1, 12, 8)
2017-06-12 11:51:17.844	INFO:	python : [DEBUG  ] ended bind vertices
2017-06-12 11:51:17.844	INFO:	python : [DEBUG  ] will bind indices
2017-06-12 11:51:17.845	INFO:	python : [DEBUG  ] glBufferSubData(target=34963 data_size=0L) (will dump first 300)
2017-06-12 11:51:17.845	INFO:	python : [DEBUG  ] ended bind indices
2017-06-12 11:51:17.845	INFO:	python : [INFO   ] glDrawElements(mode=4 indices.data_size=0)
2017-06-12 11:51:17.922	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:17.946	INFO:	art : Explicit concurrent mark sweep GC freed 38(2112B) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 180us total 23.590ms
2017-06-12 11:51:18.204	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253964968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:18.204	INFO:	DEVICE MANAGER : {"id":"1497253964968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:18.205	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253964968","orientation":"PORTRAIT"}'
2017-06-12 11:51:18.347	INFO:	python : [INFO   ] after glDrawElements
2017-06-12 11:51:18.348	INFO:	python : [INFO   ] after vertices undbind
2017-06-12 11:51:18.348	INFO:	python : [INFO   ] after indices unbind
2017-06-12 11:51:18.362	INFO:	python : [DEBUG  ] Renderer.update for batch_key=4294967295
2017-06-12 11:51:18.363	INFO:	python : [DEBUG  ] batches = [<kivent_core.rendering.batching.IndexedBatch object at 0xc5531130>]
2017-06-12 11:51:18.364	INFO:	python : [DEBUG  ] for batch = <kivent_core.rendering.batching.IndexedBatch object at 0xc5531130>, static_rendering=False force_update=False
2017-06-12 11:51:18.365	INFO:	python : [DEBUG  ] set_index_count_for_frame(index_count=3)
2017-06-12 11:51:18.371	INFO:	python : [DEBUG  ] self.current_frame=2 self.frame_count=1
2017-06-12 11:51:18.372	INFO:	python : [DEBUG  ] will bind vertices
2017-06-12 11:51:18.372	INFO:	python : [DEBUG  ] glBufferSubData(target=34962 data_size=262144L) (will dump first 300)
2017-06-12 11:51:18.373	INFO:	python : 00000000: 00 00 C8 41 00 00 C8 41  FF 00 00 FF 00 00 2F 43  ...A...A....../C
2017-06-12 11:51:18.373	INFO:	python : 00000010: 00 00 C8 41 00 FF 00 FF  00 00 C8 42 00 00 2F 43  ...A.......B../C
2017-06-12 11:51:18.373	INFO:	python : 00000020: 00 00 FF FF 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.373	INFO:	python : 00000030: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.373	INFO:	python : 00000040: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.374	INFO:	python : 00000050: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.374	INFO:	python : 00000060: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.374	INFO:	python : 00000070: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.374	INFO:	python : 00000080: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.374	INFO:	python : 00000090: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.374	INFO:	python : 000000A0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.374	INFO:	python : 000000B0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.375	INFO:	python : 000000C0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.375	INFO:	python : 000000D0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.375	INFO:	python : 000000E0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.375	INFO:	python : 000000F0: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.375	INFO:	python : 00000100: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.375	INFO:	python : 00000110: 00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  ................
2017-06-12 11:51:18.375	INFO:	python : 00000120: 00 00 00 00 00 00 00 00  00 00 00 00              ............
2017-06-12 11:51:18.376	INFO:	python : [DEBUG  ] glVertexAttribPointer(1, 2, 5126, 0, 12, 0)
2017-06-12 11:51:18.377	INFO:	python : [DEBUG  ] glVertexAttribPointer(0, 4, 5121, 1, 12, 8)
2017-06-12 11:51:18.377	INFO:	python : [DEBUG  ] ended bind vertices
2017-06-12 11:51:18.377	INFO:	python : [DEBUG  ] will bind indices
2017-06-12 11:51:18.378	INFO:	python : [DEBUG  ] glBufferData(target=34963 data_size=6L usage=35040) (will dump first 300)
2017-06-12 11:51:18.378	INFO:	python : 00000000: 00 00 01 00 02 00                                 ......
2017-06-12 11:51:18.379	INFO:	python : [DEBUG  ] ended bind indices
2017-06-12 11:51:18.379	INFO:	python : [INFO   ] glDrawElements(mode=4 indices.data_size=6)
2017-06-12 11:51:18.379	INFO:	python : --------- beginning of crash
2017-06-12 11:51:18.380	ASSERT:	libc : Fatal signal 11 (SIGSEGV), code 1, fault addr 0x34 in tid 9579 (SDLThread)
2017-06-12 11:51:18.394	WARN:	 : debuggerd: handling request: pid=9536 uid=10132 gid=10132 tid=9579
2017-06-12 11:51:18.407	WARN:	debuggerd : type=1400 audit(0.0:68): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:69): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:70): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:71): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:72): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:73): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:74): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:75): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:76): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:77): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:78): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:79): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:80): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:81): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.411	WARN:	debuggerd : type=1400 audit(0.0:82): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.414	WARN:	debuggerd : type=1400 audit(0.0:83): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.414	WARN:	debuggerd : type=1400 audit(0.0:84): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.414	WARN:	debuggerd : type=1400 audit(0.0:85): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.414	WARN:	debuggerd : type=1400 audit(0.0:86): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.414	WARN:	debuggerd : type=1400 audit(0.0:87): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.414	WARN:	debuggerd : type=1400 audit(0.0:88): avc: denied { search } for name="org.test.myapp" dev="dm-2" ino=1504592 scontext=u:r:debuggerd:s0 tcontext=u:object_r:app_data_file:s0:c512,c768 tclass=dir permissive=0
2017-06-12 11:51:18.497	ASSERT:	DEBUG : *** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***
2017-06-12 11:51:18.497	ASSERT:	DEBUG : Build fingerprint: 'google/bullhead/bullhead:7.1.2/N2G47O/3852959:user/release-keys'
2017-06-12 11:51:18.497	ASSERT:	DEBUG : Revision: 'rev_1.0'
2017-06-12 11:51:18.497	ASSERT:	DEBUG : ABI: 'arm'
2017-06-12 11:51:18.498	ASSERT:	DEBUG : pid: 9536, tid: 9579, name: SDLThread  >>> org.test.myapp <<<
2017-06-12 11:51:18.498	ASSERT:	DEBUG : signal 11 (SIGSEGV), code 1 (SEGV_MAPERR), fault addr 0x34
2017-06-12 11:51:18.498	ASSERT:	DEBUG : r0 cdfda254  r1 00000000  r2 ce2c9e80  r3 dc22120c
2017-06-12 11:51:18.498	ASSERT:	DEBUG : r4 ce2c9ed4  r5 00008be7  r6 00000001  r7 00000060
2017-06-12 11:51:18.498	ASSERT:	DEBUG : r8 ce2f12c0  r9 ce2c9ed4  sl 00000000  fp 00000000
2017-06-12 11:51:18.498	ASSERT:	DEBUG : ip 00000000  sp cfec5d78  lr dc1131ff  pc dc113204  cpsr 800f0030
2017-06-12 11:51:18.503	ASSERT:	DEBUG : backtrace:
2017-06-12 11:51:18.504	ASSERT:	DEBUG : #00 pc 000d3204  /vendor/lib/egl/libGLESv2_adreno.so
2017-06-12 11:51:18.504	ASSERT:	DEBUG : #01 pc 000d79bb  /vendor/lib/egl/libGLESv2_adreno.so (_ZN21EsxGlApiParamValidate14GlDrawElementsEP11EsxDispatchjijPKv+122)
2017-06-12 11:51:18.504	ASSERT:	DEBUG : #02 pc 00096f83  /vendor/lib/egl/libGLESv2_adreno.so (glDrawElements+34)
2017-06-12 11:51:18.504	ASSERT:	DEBUG : #03 pc 0000828b  /data/data/org.test.myapp/files/app/lib/python2.7/site-packages/kivent_core/rendering/batching.so
2017-06-12 11:51:18.704	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253965468","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:18.705	INFO:	DEVICE MANAGER : {"id":"1497253965468","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:18.707	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253965468","orientation":"PORTRAIT"}'
2017-06-12 11:51:19.204	INFO:	TOOLKIT SERVICE : Request body '{"id":"1497253965968","type":"GET_SCREEN_ORIENTATION"}'
2017-06-12 11:51:19.205	INFO:	DEVICE MANAGER : {"id":"1497253965968","type":"GET_SCREEN_ORIENTATION"}
2017-06-12 11:51:19.207	INFO:	TOOLKIT SERVICE : Responding to client with: '{"id":"1497253965968","orientation":"PORTRAIT"}'
2017-06-12 11:51:19.426	INFO:	art : Starting a blocking GC Explicit
2017-06-12 11:51:19.455	INFO:	art : Explicit concurrent mark sweep GC freed 38(2112B) AllocSpace objects, 0(0B) LOS objects, 40% free, 18MB/30MB, paused 311us total 27.896ms
2017-06-12 11:51:19.594	WARN:	ActivityManager : Force finishing activity org.test.myapp/org.kivy.android.PythonActivity
2017-06-12 11:51:19.607	WARN:	 : debuggerd: resuming target 9536
2017-06-12 11:51:19.609	INFO:	BootReceiver : Copying /data/tombstones/tombstone_01 to DropBox (SYSTEM_TOMBSTONE)
2017-06-12 11:51:19.615	ERROR:	lowmemorykiller : Error writing /proc/9536/oom_score_adj; errno=22
2017-06-12 11:51:19.616	WARN:	ActivityManager : Failed setting process group of 9536 to 1
2017-06-12 11:51:19.616	WARN:	System.err : java.lang.IllegalArgumentException: Given thread 9565 does not exist
2017-06-12 11:51:19.616	WARN:	System.err : at android.os.Process.setThreadPriority(Native Method)
2017-06-12 11:51:19.616	WARN:	System.err : at com.android.server.am.ActivityManagerService.applyOomAdjLocked(ActivityManagerService.java:20546)
2017-06-12 11:51:19.616	WARN:	System.err : at com.android.server.am.ActivityManagerService.updateOomAdjLocked(ActivityManagerService.java:21048)
2017-06-12 11:51:19.616	WARN:	System.err : at com.android.server.am.BroadcastQueue.processCurBroadcastLocked(BroadcastQueue.java:274)
2017-06-12 11:51:19.616	WARN:	System.err : at com.android.server.am.BroadcastQueue.processNextBroadcast(BroadcastQueue.java:1225)
2017-06-12 11:51:19.616	WARN:	System.err : at com.android.server.am.BroadcastQueue$BroadcastHandler.handleMessage(BroadcastQueue.java:172)
2017-06-12 11:51:19.616	WARN:	System.err : at android.os.Handler.dispatchMessage(Handler.java:102)
2017-06-12 11:51:19.616	WARN:	System.err : at android.os.Looper.loop(Looper.java:154)
2017-06-12 11:51:19.616	WARN:	System.err : at android.os.HandlerThread.run(HandlerThread.java:61)
2017-06-12 11:51:19.616	WARN:	System.err : at com.android.server.ServiceThread.run(ServiceThread.java:46)
2017-06-12 11:51:19.663	INFO:	OpenGLRenderer : Initialized EGL, version 1.4
2017-06-12 11:51:19.663	DEBUG:	OpenGLRenderer : Swap behavior 1
2017-06-12 11:51:19.674	INFO:	WindowManager : WIN DEATH: Window{2fcb3e1 u0 SurfaceView - org.test.myapp/org.kivy.android.PythonActivity}
2017-06-12 11:51:19.675	DEBUG:	GraphicsStats : Buffer count: 3
2017-06-12 11:51:19.675	INFO:	sensors : activate
2017-06-12 11:51:19.675	INFO:	ActivityManager : Process org.test.myapp (pid 9536) has died
2017-06-12 11:51:19.675	DEBUG:	ActivityManager : cleanUpApplicationRecord -- 9536
2017-06-12 11:51:19.677	INFO:	nanohub : queueActivate: sensor=1, handle=1, enable=0
2017-06-12 11:51:19.679	INFO:	nanohub : osLog: [BMI160] accSetRate: rate=51200, latency=-256, state=3
2017-06-12 11:51:19.681	INFO:	Zygote : Process 9536 exited due to signal (11)
2017-06-12 11:51:19.691	WARN:	InputDispatcher : channel '1a08ca0 org.test.myapp/org.kivy.android.PythonActivity (server)' ~ Consumer closed input channel or an error occurred.  events=0x9
2017-06-12 11:51:19.691	ERROR:	InputDispatcher : channel '1a08ca0 org.test.myapp/org.kivy.android.PythonActivity (server)' ~ Channel is unrecoverably broken and will be disposed!
2017-06-12 11:51:19.692	INFO:	WindowManager : WIN DEATH: Window{1a08ca0 u0 org.test.myapp/org.kivy.android.PythonActivity}
2017-06-12 11:51:19.692	WARN:	InputDispatcher : Attempted to unregister already unregistered input channel '1a08ca0 org.test.myapp/org.kivy.android.PythonActivity (server)'

@maho
Copy link
Contributor Author

maho commented Jun 12, 2017

I have idea that I could write testcase of bug in adreno drivers in pure opengl. To be able to report to them or (more likely) search for workaround.

Could someone show me simple example of android app (python for android or just java android) like "draw triangle in opengl"?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants