hoccer / hoccer-talk-spike

Android Client & Backend Software
0 stars 0 forks source link

Failed Log in / network information constantly displaying "log in" #765

Closed ChristianeMussmacher closed 9 years ago

ChristianeMussmacher commented 9 years ago

version 3.1.4 tested on several devices barely reproducible


Sometimes a client is not able to log in (network information displaying "Anmeldung"). Connecting is only possible after restarting the application.

j-era commented 9 years ago

Log from Nexus 5

03-12 15:43:33.916    6622-7044/? I/Hoccer﹕ [client-40] INFO  com.hoccer.talk.client.XoClient - [switchState: connection #1] state connecting -> syncing (login successful)
03-12 15:43:33.918    6622-7043/? I/Hoccer﹕ [client-39] INFO  a.a.b.a - RPC-Request -> [1] {"id":"7b","jsonrpc":"2.0","method":"hello","params":[{"clientBuildVariant":"release","clientLanguage":"en","clientName":"com.artcom.hoccer","clientTime":1426171413917,"clientVersion":"3.1.4","deviceModel":"LGE Nexus 5","systemLanguage":"en","systemName":"Android","systemVersion":"5.0.1","clientBuildNumber":352}]}
03-12 15:43:35.930   6622-18037/? I/Hoccer﹕ [Thread-734] INFO  com.hoccer.talk.client.XoTransferAgent - startOrRestartDownload()
03-12 15:43:35.930   6622-18037/? I/Hoccer﹕ [Thread-734] INFO  com.hoccer.talk.client.XoTransferAgent - download 6 already scheduled in state 'DOWNLOADING'
03-12 15:43:38.928      748-748/? I/ActivityManager﹕ Killing 6219:com.android.cellbroadcastreceiver/u0a29 (adj 15): empty for 1817s
03-12 15:44:38.928      748-748/? I/ActivityManager﹕ Killing 11590:com.google.android.talk/u0a51 (adj 15): empty for 1815s
03-12 15:45:01.227   1267-12506/? D/GCM﹕ Message class com.google.e.a.a.h
03-12 15:49:36.681     748-1230/? I/ActivityManager﹕ Start proc android.process.acore for content provider com.android.providers.contacts/.ContactsProvider2: pid=19013 uid=10003 gids={50003, 9997} abi=armeabi-v7a
03-12 15:49:37.796      748-763/? I/ActivityManager﹕ START u0 {act=android.media.action.IMAGE_CAPTURE flg=0x3 cmp=com.google.android.GoogleCamera/com.android.camera.CaptureActivity (has clip) (has extras)} from uid 10073 on display 0
03-12 15:49:37.802      748-763/? W/ResourcesManager﹕ Asset path '/system/framework/com.google.android.camera2.jar' does not exist or contains no resources.
03-12 15:49:37.864     748-1145/? I/ActivityManager﹕ Start proc com.google.android.GoogleCamera for activity com.google.android.GoogleCamera/com.android.camera.CaptureActivity: pid=19033 uid=10042 gids={50042, 9997, 3003, 1028, 1015} abi=armeabi-v7a
03-12 15:49:37.919  19033-19033/? W/ResourcesManager﹕ Asset path '/system/framework/com.google.android.camera2.jar' does not exist or contains no resources.
03-12 15:49:38.317    6622-6622/? I/Hoccer﹕ [main] INFO  com.hoccer.xo.android.BackgroundManager - Application went to background
03-12 15:49:38.473     748-1359/? I/ActivityManager﹕ Start proc android.process.media for content provider com.android.providers.media/.MediaProvider: pid=19095 uid=10005 gids={50005, 9997, 2001, 3003, 1028, 1015, 3007, 1023, 1024} abi=armeabi-v7a
03-12 15:49:38.556      185-185/? I/Camera2ClientBase﹕ Camera 0: Opened. Client: com.google.android.GoogleCamera (PID 19033, UID 10042)
03-12 15:49:38.664  19095-19095/? E/SQLiteLog﹕ (283) recovered 93 frames from WAL file /data/user/0/com.android.providers.media/databases/external.db-wal
03-12 15:49:38.832      748-817/? I/ActivityManager﹕ Displayed com.google.android.GoogleCamera/com.android.camera.CaptureActivity: +1s0ms
03-12 15:49:38.868    6622-6622/? W/Hoccer﹕ [main] WARN  com.hoccer.xo.android.XoApplication - Received onTrimMemory(20).
03-12 15:49:39.105      748-829/? I/ActivityManager﹕ START u0 {act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10200000 cmp=com.google.android.googlequicksearchbox/com.google.android.launcher.GEL} from uid 1000 on display 0
03-12 15:49:39.617      185-185/? I/Camera2ClientBase﹕ Closed Camera 0. Client was: com.google.android.GoogleCamera (PID 19033, UID 10042)
03-12 15:49:39.649    1219-1219/? I/GEL﹕ handleIntent(Intent { act=android.intent.action.MAIN cat=[android.intent.category.HOME] flg=0x10600000 cmp=com.google.android.googlequicksearchbox/com.google.android.launcher.GEL })
03-12 15:49:39.862   3034-19202/? I/MicrophoneInputStream﹕ mic_starting com.google.android.speech.audio.w@14cae1d2
03-12 15:49:39.874   3034-19202/? I/MicrophoneInputStream﹕ mic_started com.google.android.speech.audio.w@14cae1d2
03-12 15:49:40.850      748-764/? D/ConnectivityService﹕ setProvNotificationVisible: E visible=false networkType=0 action=com.android.internal.telephony.PROVISION0
03-12 15:49:40.872    748-19239/? D/NetworkMonitorNetworkAgentInfo [MOBILE (UMTS) - null]﹕ DefaultState{ when=-2ms what=532481 target=com.android.internal.util.StateMachine$SmHandler }
03-12 15:49:40.872    748-19239/? D/NetworkMonitorNetworkAgentInfo [MOBILE (UMTS) - null]﹕ EvaluatingState{ when=-1ms what=532486 arg1=1 target=com.android.internal.util.StateMachine$SmHandler }
03-12 15:49:41.778      748-812/? I/ActivityManager﹕ Start proc com.android.cellbroadcastreceiver for broadcast com.android.cellbroadcastreceiver/.CellBroadcastReceiver: pid=19257 uid=10029 gids={50029, 9997} abi=armeabi-v7a
03-12 15:49:41.835  19257-19257/? D/CellBroadcastReceiver﹕ onReceive Intent { act=android.intent.action.SERVICE_STATE flg=0x10 cmp=com.android.cellbroadcastreceiver/.CellBroadcastReceiver (has extras) }
03-12 15:49:41.850    1195-3831/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4352 to 4354 from client com.android.cellbroadcastreceiver
03-12 15:49:41.854    1195-1234/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4356 to 4356 from client com.android.cellbroadcastreceiver
03-12 15:49:41.857    1195-2717/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4371 to 4372 from client com.android.cellbroadcastreceiver
03-12 15:49:41.861    1195-3042/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4373 to 4378 from client com.android.cellbroadcastreceiver
03-12 15:49:41.949    1195-1234/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4379 to 4379 from client com.android.cellbroadcastreceiver
03-12 15:49:41.965    1195-1227/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4370 to 4370 from client com.android.cellbroadcastreceiver
03-12 15:49:41.969    1195-2816/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4383 to 4383 from client com.android.cellbroadcastreceiver
03-12 15:49:41.973    1195-3042/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Failed to remove cell broadcast subscription for MID range 50 to 50 from client com.android.cellbroadcastreceiver
03-12 15:49:41.976    1195-2816/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Failed to remove cell broadcast subscription for MID range 919 to 928 from client com.android.cellbroadcastreceiver
03-12 15:49:41.977    1195-3042/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Failed to remove cell broadcast subscription for MID range 4355 to 4355 from client com.android.cellbroadcastreceiver
03-12 15:49:41.978    1195-3831/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Failed to remove cell broadcast subscription for MID range 4380 to 4382 from client com.android.cellbroadcastreceiver
03-12 15:49:41.980     748-1166/? I/ActivityManager﹕ Killing 13344:com.google.android.gm.exchange/u0a91 (adj 15): empty for 1913s
03-12 15:49:41.996    748-19239/? D/NetworkMonitorNetworkAgentInfo [MOBILE (UMTS) - null]﹕ ValidatedState{ when=0 what=532487 target=com.android.internal.util.StateMachine$SmHandler }
03-12 15:49:41.996    748-19239/? D/NetworkMonitorNetworkAgentInfo [MOBILE (UMTS) - null]﹕ DefaultState{ when=0 what=532487 target=com.android.internal.util.StateMachine$SmHandler }
03-12 15:49:42.307     748-1250/? I/ActivityManager﹕ START u0 {act=com.android.systemui.recents.SHOW_RECENTS flg=0x10804000 cmp=com.android.systemui/.recents.RecentsActivity (has extras)} from uid 10012 on display 0
03-12 15:49:42.317    3034-4382/? I/MicrophoneInputStream﹕ mic_close com.google.android.speech.audio.w@14cae1d2
03-12 15:49:42.325      893-893/? W/PackageManager﹕ Failure retrieving resources for com.android.vending: Resource ID #0x0
03-12 15:49:42.344      893-893/? W/PackageManager﹕ Failure retrieving resources for com.android.settings: Resource ID #0x0
03-12 15:49:42.358      893-893/? W/PackageManager﹕ Failure retrieving resources for com.artcom.hoccer: Resource ID #0x0
03-12 15:49:43.248  19257-19257/? D/CellBroadcastReceiver﹕ onReceive Intent { act=android.intent.action.SERVICE_STATE flg=0x10 cmp=com.android.cellbroadcastreceiver/.CellBroadcastReceiver (has extras) }
03-12 15:49:43.254    1195-1227/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4352 to 4354 from client com.android.cellbroadcastreceiver
03-12 15:49:43.257    1195-1234/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4356 to 4356 from client com.android.cellbroadcastreceiver
03-12 15:49:43.261    1195-2816/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4371 to 4372 from client com.android.cellbroadcastreceiver
03-12 15:49:43.264    1195-3042/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4373 to 4378 from client com.android.cellbroadcastreceiver
03-12 15:49:43.267    1195-3831/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4379 to 4379 from client com.android.cellbroadcastreceiver
03-12 15:49:43.271    1195-2717/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4370 to 4370 from client com.android.cellbroadcastreceiver
03-12 15:49:43.274    1195-1227/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Added cell broadcast subscription for MID range 4383 to 4383 from client com.android.cellbroadcastreceiver
03-12 15:49:43.278    1195-1234/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Failed to remove cell broadcast subscription for MID range 50 to 50 from client com.android.cellbroadcastreceiver
03-12 15:49:43.280    1195-1227/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Failed to remove cell broadcast subscription for MID range 919 to 928 from client com.android.cellbroadcastreceiver
03-12 15:49:43.281    1195-1234/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Failed to remove cell broadcast subscription for MID range 4355 to 4355 from client com.android.cellbroadcastreceiver
03-12 15:49:43.282    1195-2816/? D/IccSmsInterfaceManager﹕ [IccSmsInterfaceManager] Failed to remove cell broadcast subscription for MID range 4380 to 4382 from client com.android.cellbroadcastreceiver
03-12 15:49:43.531      185-185/? I/Camera2ClientBase﹕ Camera 0: Opened. Client: com.google.android.GoogleCamera (PID 19033, UID 10042)
03-12 15:49:43.576    1566-1566/? I/GCoreUlr﹕ Received powerMode change from NLP: com.google.android.location.activity.LOW_POWER_MODE_ENABLED
03-12 15:49:43.576    1566-1566/? I/GCoreUlr﹕ Starting service, intent=Intent { act=com.google.android.location.reporting.ACTION_UPDATE_ACTIVE_STATE cmp=com.google.android.gms/com.google.android.location.reporting.service.DispatchingService (has extras) }, extras=Bundle[{source=PowerModeReceiver}]
03-12 15:49:43.669    1566-1674/? I/GCoreUlr﹕ Starting service, intent=Intent { act=com.google.android.location.reporting.ACTION_LOCATION_STATUS cmp=com.google.android.gms/com.google.android.location.reporting.service.DispatchingService (has extras) }, extras=Bundle[{status=LocationStatus[cell status: STATUS_SUCCESSFUL, wifi status: STATUS_SUCCESSFUL, elapsed realtime ns: 1268531252021]}]
03-12 15:49:45.744      748-812/? W/ActivityManager﹕ Activity pause timeout for ActivityRecord{222cab4e u0 com.google.android.GoogleCamera/com.android.camera.CaptureActivity t610 f}
03-12 15:49:45.761      185-853/? I/Camera2ClientBase﹕ Closed Camera 0. Client was: com.google.android.GoogleCamera (PID 19033, UID 10042)
03-12 15:49:45.781    6622-6622/? I/Hoccer﹕ [main] INFO  com.hoccer.talk.client.XoClient - sendPresence()
03-12 15:49:45.782    6622-7224/? I/Hoccer﹕ [client-76] INFO  com.hoccer.talk.client.XoClient - using key with key id db45c3f18948b3ac
03-12 15:49:45.783    6622-6622/? I/Hoccer﹕ [main] INFO  com.hoccer.xo.android.BackgroundManager - Application went to foreground
03-12 15:49:45.784    6622-6622/? D/HockeyApp﹕ Looking for exceptions in: /data/data/com.artcom.hoccer/files
03-12 15:49:45.805    6622-7224/? E/Hoccer﹕ [client-76] ERROR com.hoccer.talk.client.XoClient - error in sendPresence
    java.lang.reflect.UndeclaredThrowableException
            at $Proxy4.updateKey(Unknown Source)
            at com.hoccer.talk.client.XoClient$30.run(XoClient.java:1931)
            at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422)
            at java.util.concurrent.FutureTask.run(FutureTask.java:237)
            at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:152)
            at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:265)
            at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
            at java.lang.Thread.run(Thread.java:818)
     Caused by: java.io.IOException: Websocket not open
            at a.a.g.c.a(JsonRpcWsConnection.java:124)
            at a.a.g.c.a(JsonRpcWsConnection.java:134)
            at a.a.g.c.a(JsonRpcWsConnection.java:246)
            at a.a.b.a.a(JsonRpcClient.java:262)
            at a.a.b.a.a(JsonRpcClient.java:342)
            at a.a.f.b$1.invoke(ProxyUtil.java:152)
            at java.lang.reflect.Proxy.invoke(Proxy.java:397)
            at $Proxy4.updateKey(Unknown Source)
            at com.hoccer.talk.client.XoClient$30.run(XoClient.java:1931)
            at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422)
            at java.util.concurrent.FutureTask.run(FutureTask.java:237)
            at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:152)
            at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:265)
            at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
            at java.lang.Thread.run(Thread.java:818)
xadh00m commented 9 years ago

Reviewed with @j3nsm4n, merged in 1520ff8.

xadh00m commented 9 years ago

A connection issue observed during tests has been fixed.

Reviewed with @j3nsm4n, merged in 37f41fa.