LwIP SIGABRTs

[ignoramous]

Looks like the TCP connections are being closed / aborted when the connection hasn't even been accepted yet. All indications are lwip-callbacks into outline-go-tun2socks couldn't have caused these because these callbacks are called after a TCP connection has been accepted.

Likely, this pull request that simplifies tcp-conn-key management might fix these SIGBARTs: github/eycorsican/go-tun2socks/pull/117.

2020-09-01 23:13:35.376 10897-11041/com.celzero.bravedns A/libc: Fatal signal 6 (SIGABRT), code -1 (SI_QUEUE) in tid 11041 (Thread-8), pid 10897 (elzero.bravedns)
2020-09-01 23:13:35.418 10897-5542/com.celzero.bravedns I/GoLog: Assertion "tcp_pcbs_sane: active pcb->state != LISTEN" failed at line 2522 in /tmp/gomobile-work-252469056/pkg/mod/github.com/eycorsican/[email protected]/core/c/core/tcp.c
23:19

2020-09-01 21:07:07.343 24585-24585/com.celzero.bravedns E/BraveDNS: VPN controller stop called
2020-09-01 21:07:07.350 24585-24785/com.celzero.bravedns I/GoLog: Assertion "don't call tcp_abort/tcp_abandon for listen-pcbs" failed at line 577 in /tmp/gomobile-work-252469056/pkg/mod/github.com/eycorsican/[email protected]/core/c/core/tcp.c
2020-09-01 21:07:09.057 24585-24785/com.celzero.bravedns E/GoLog: [0901/210709.033579:ERROR:elf_dynamic_array_reader.h(61)] tag not found

2020-09-01 21:07:09.072 24585-24585/com.celzero.bravedns A/libc: Fatal signal 6 (SIGABRT), code -6 (SI_TKILL) in tid 24585 (elzero.bravedns), pid 24585 (elzero.bravedns)
2020-09-01 21:07:09.331 10539-10539/? A/DEBUG: pid: 24585, tid: 24585, name: elzero.bravedns  >>> com.celzero.bravedns <<<
2020-09-01 21:07:09.343 10539-10539/? A/DEBUG:       #01 pc 00000000005d2144  /data/app/com.celzero.bravedns-AY92xbnPwCGG6SBg4brF_Q==/base.apk (offset 0x1ce000) (tcp_abandon+640)
2020-09-01 21:07:10.347 8453-10542/? W/ActivityTaskManager:   Force finishing activity com.celzero.bravedns/.ui.HomeScreenActivity
2020-09-01 21:07:10.488 8453-8603/? W/InputDispatcher: channel '1991741 com.celzero.bravedns/com.celzero.bravedns.ui.HomeScreenActivity (server)' ~ Consumer closed input channel or an error occurred.  events=0xd
2020-09-01 21:07:10.488 8453-8603/? E/InputDispatcher: channel '1991741 com.celzero.bravedns/com.celzero.bravedns.ui.HomeScreenActivity (server)' ~ Channel is unrecoverably broken and will be disposed!
2020-09-01 21:07:10.542 8355-15830/? I//vendor/bin/hw/[email protected]: unbindService is called for service : com.celzero.bravedns/.service.BraveVPNService and for client system
2020-09-01 21:07:10.542 8355-15830/? I//vendor/bin/hw/[email protected]: size of service connections for service: com.celzero.bravedns/.service.BraveVPNServiceafter removal is 0
2020-09-01 21:07:10.564 8453-8485/? W/ActivityManager: Exception when unbinding service com.celzero.bravedns/.service.BraveVPNService
    android.os.DeadObjectException
        at android.os.BinderProxy.transactNative(Native Method)
        at android.os.BinderProxy.transact(BinderProxy.java:510)
        at android.app.IApplicationThread$Stub$Proxy.scheduleUnbindService(IApplicationThread.java:1612)
        at com.android.server.am.ActiveServices.removeConnectionLocked(ActiveServices.java:3339)
        at com.android.server.am.ActiveServices.unbindServiceLocked(ActiveServices.java:2023)
        at com.android.server.am.ActivityManagerService.unbindService(ActivityManagerService.java:14166)
        at android.app.ContextImpl.unbindService(ContextImpl.java:1779)
        at com.android.server.connectivity.Vpn$2.interfaceRemoved(Vpn.java:1462)
        at com.android.server.NetworkManagementService.lambda$notifyInterfaceRemoved$3(NetworkManagementService.java:379)
        at com.android.server.-$$Lambda$NetworkManagementService$FsR_UD5xfj4hgrwGdX74wq881Bk.sendCallback(Unknown Source:2)
        at com.android.server.NetworkManagementService.invokeForAllObservers(NetworkManagementService.java:340)
        at com.android.server.NetworkManagementService.notifyInterfaceRemoved(NetworkManagementService.java:379)
        at com.android.server.NetworkManagementService.access$600(NetworkManagementService.java:117)
        at com.android.server.NetworkManagementService$NetdUnsolicitedEventListener.lambda$onInterfaceRemoved$6$NetworkManagementService$NetdUnsolicitedEventListener(NetworkManagementService.java:702)
        at com.android.server.-$$Lambda$NetworkManagementService$NetdUnsolicitedEventListener$h2iz-IbnHpQ97mlJ7G62W2mmanw.run(Unknown Source:4)
        at android.os.Handler.handleCallback(Handler.java:883)
        at android.os.Handler.dispatchMessage(Handler.java:100)
        at android.os.Looper.loop(Looper.java:214)
        at android.os.HandlerThread.run(HandlerThread.java:67)
        at com.android.server.ServiceThread.run(ServiceThread.java:44)
2020-09-01 21:07:10.665 8453-8495/? W/BroadcastQueue: Skipping deliver [background] BroadcastRecord{5c30593 u-1 android.net.conn.CONNECTIVITY_CHANGE} to ReceiverList{5d88649 24585 com.celzero.bravedns/10713/u0 remote:6eaa450}: process gone or crashing
2020-09-01 21:07:10.742 8453-8495/? W/ActivityManager: Failed to update http proxy for: com.celzero.bravedns
2020-09-01 21:07:10.769 8453-8495/? W/BroadcastQueue: Skipping deliver [background] BroadcastRecord{905d832 u-1 android.intent.action.PROXY_CHANGE} to ReceiverList{c789e53 24585 com.celzero.bravedns/10713/u0 remote:55f4e42}: process gone or crashing
2020-09-01 21:07:10.817 8453-18478/? I/WindowManager: WIN DEATH: Window{1991741 u0 com.celzero.bravedns/com.celzero.bravedns.ui.HomeScreenActivity}
2020-09-01 21:07:10.817 8453-18478/? W/InputDispatcher: Attempted to unregister already unregistered input channel '1991741 com.celzero.bravedns/com.celzero.bravedns.ui.HomeScreenActivity (server)'
2020-09-01 21:07:10.846 8453-9899/? I/ActivityManager: Process com.celzero.bravedns (pid 24585) has died: fore  +50 TOP
2020-09-01 21:07:10.851 8453-8488/? W/ActivityTaskManager: Activity top resumed state loss timeout for ActivityRecord{328faa4 u0 com.celzero.bravedns/.ui.HomeScreenActivity t13843 f}
2020-09-01 21:07:10.853 8355-15830/? I//vendor/bin/hw/[email protected]: removing client with pid 24585process namecom.celzero.bravedns
2020-09-01 21:07:12.672 8453-8609/? I/ActivityTaskManager: START u0 {cmp=com.celzero.bravedns/.ui.HomeScreenActivity} from uid 10713
2020-09-01 21:07:12.673 8453-8609/? W/ActivityTaskManager: startActivity called from non-Activity context; forcing Intent.FLAG_ACTIVITY_NEW_TASK for: Intent { cmp=com.celzero.bravedns/.ui.HomeScreenActivity }
2020-09-01 21:07:12.677 719-3225/? E/ANDR-PERF-LM: PreKillAction: updateAppServices() 385: AppName = com.celzero.bravedns, service Name = com.google.android.gms/.chimera.PersistentDirectBootAwareApiService service PID = 9272
2020-09-01 21:07:12.677 719-3225/? E/ANDR-PERF-LM: PreKillAction: updateAppServices() 385: AppName = com.celzero.bravedns, service Name =  service PID = -1
2020-09-01 21:07:12.677 719-3225/? E/ANDR-PERF-LM: PreKillAction: updateAppServices() 385: AppName = com.celzero.bravedns, service Name =  service PID = -1
2020-09-01 21:07:12.677 719-3225/? E/ANDR-PERF-LM: PreKillAction: updateAppServices() 387: inRAMServiceSet size for AppName = com.celzero.bravedns is 1
2020-09-01 21:07:12.677 719-3225/? E/ANDR-PERF-LM: PreKillAction: applyAction() 484: (appName,hintID,memoryToGenerate,memoryGenerated, surplusMemory) = (com.celzero.bravedns ,4225, 0.000000, 0.000000, 0.000000)
2020-09-01 21:07:12.677 719-3225/? E/ANDR-PERF-LM: PreKillAction: applyAction() 496: (Service - appName,hintID,memoryToGenerate,memoryGenerated, surplusServiceMemory) = (com.celzero.bravedns ,4225, 0.000000, 0.000000, 0.000000)

[ignoramous]

We saw this happen with udp connection too. From the limited logs, presumably what happened is, the LwIP stack was closed (and the callbacks removed) whilst a UDP socket was still busy writing its packet to a (local) destination in-parallel.

[ignoramous]

These still do happen in-the-wild, but with a potential move to either gVisor NetStack (celzero/firestack#3) or eycorsican's leaf on the cards, this is as far as we investigate this, as eycorsican's go-tun2socks is now archived.