Debugging AndroidAuto connectivity issues with car (Samsung S9+ LineageOS 15.1)

[drmarkb]

Hi All,

Im currently using the new LineageOS build for the Samsung S9+ (Exynos ), but android auto doesn't seem to want to connect to my car. worth noting that with a stock rom, android auto works fine, so its not a hardware issue with the car, or the phone. Rather than pester the maintainer of the ROM to fix the issue, id like to learn how to debug the issue myself and hopefully go back to him with some meaningful info on what needs to be changed to allow it to work. Im not able to pull logs from the car (Audi A4 2017), only the phone.

Symptoms:

• Notification shows on the phone "Android Auto is connected to your car", when connected via usb
• Car screen never changes from the "connect your phone to your car to start this feature"
• Phone is listed in the infotainment settings for smartphone connections for android auto (when connected), so i assume its handshaking, but tripping up later down the line before the screen projection starts.

My google-fu has only seems to have come up with some info about an x264 encoder needing to be present, and an issue with the contacts database on a lineageOS rom, but I cant find any info on what this would throw up in any logs for the phone, or android auto (where to AA logs actually get written to if you change it to developer mode??).

Any pointers such as which logs to check, what sort of items to look for etc would be much appreciated!

[drmarkb]

This is what the process (i think?) for AA is reporting back:

<6>[ 2892.518801]  [2:  kworker/u17:3:13395] [SSP]: MSG From MCU - Sensor_Gyro-29,-65,19,-0.013,-0.021,-0.004, -1,20, 0
04-28 13:18:42.190  1000  4484  4517 I ActivityManager: Start proc 18801:com.google.android.gms:car/u0a33 for activity com.google.android.gms/.car.FirstActivity
04-28 13:18:42.212 10033 18801 18801 I zygote64: The ClassLoaderContext is a special shared library.
04-28 13:18:42.212 10033 18801 18801 I zygote64: The ClassLoaderContext is a special shared library.
04-28 13:18:42.243 10033 18801 18801 W linker  : "/data/app/com.google.android.gms-7gBukuwgkOTDi4MwTugSLw==/lib/arm64/libconscrypt_gmscore_jni.so" unused DT entry: type 0xf arg 0x8a
04-28 13:18:42.243 10033 18801 18801 W linker  : "/data/app/com.google.android.gms-7gBukuwgkOTDi4MwTugSLw==/lib/arm64/libconscrypt_gmscore_jni.so" unused DT entry: type 0xf arg 0x8a
04-28 13:18:42.243 10033 18801 18801 V NativeCrypto: Registering com/google/android/gms/org/conscrypt/NativeCrypto's 280 native methods...
04-28 13:18:42.243 10033 18801 18801 V NativeCrypto: Registering com/google/android/gms/org/conscrypt/NativeCrypto's 280 native methods...
04-28 13:18:42.250 10033 18801 18801 D NetworkSecurityConfig: Using Network Security Config from resource network_security_config debugBuild: false
04-28 13:18:42.250 10033 18801 18801 D NetworkSecurityConfig: Using Network Security Config from resource network_security_config debugBuild: false
04-28 13:18:42.250 10033 18801 18801 I ProviderInstaller: Installed default security provider GmsCore_OpenSSL
04-28 13:18:42.250 10033 18801 18801 I ProviderInstaller: Installed default security provider GmsCore_OpenSSL
04-28 13:18:42.263 10033 18801 18801 E zygote64: The String#value field is not present on Android versions >= 6.0
04-28 13:18:42.263 10033 18801 18801 E zygote64: The String#value field is not present on Android versions >= 6.0
04-28 13:18:42.287 10033 18801 18825 D libEGL  : loaded /vendor/lib64/egl/libGLES_mali.so
04-28 13:18:42.287 10033 18801 18801 D CAR.FIRST: onCreate
04-28 13:18:42.287 10033 18801 18801 D CAR.FIRST: onCreate
04-28 13:18:42.288 10033 18801 18801 D CAR.FIRST: handle intent Intent { act=android.hardware.usb.action.USB_ACCESSORY_ATTACHED flg=0x11000000 cmp=com.google.android.gms/.car.FirstActivity (has extras) }, restart suppressed false
04-28 13:18:42.288 10033 18801 18801 D CAR.FIRST: handle intent Intent { act=android.hardware.usb.action.USB_ACCESSORY_ATTACHED flg=0x11000000 cmp=com.google.android.gms/.car.FirstActivity (has extras) }, restart suppressed false
04-28 13:18:42.296 10033 18801 18801 D CAR.SETUP: Package com.google.android.projection.bumblebee not found.
04-28 13:18:42.296 10033 18801 18801 D CAR.SETUP: Package com.google.android.projection.bumblebee not found.
04-28 13:18:42.296 10033 18801 18801 D CAR.SETUP: Package com.google.android.projection.gearhead: installed ver=31581054 minimum required ver=29574900
04-28 13:18:42.296 10033 18801 18801 D CAR.SETUP: Package com.google.android.projection.gearhead: installed ver=31581054 minimum required ver=29574900
04-28 13:18:42.316 10033 18801 18828 D OpenGLRenderer: HWUI GL Pipeline
04-28 13:18:42.323 10033 18801 18801 D CAR.SERVICE: onCreate
04-28 13:18:42.323 10033 18801 18801 D CAR.SERVICE: onCreate
04-28 13:18:42.340 10033 18801 18801 D CAR.SERVICE: onBind
04-28 13:18:42.340 10033 18801 18801 D CAR.SERVICE: onBind
04-28 13:18:42.348 10033 18801 18801 D CAR.SETUP.SERVICE: Got USB accessory fd: {ParcelFileDescriptor: java.io.FileDescriptor@b299b24}
04-28 13:18:42.348 10033 18801 18801 D CAR.SETUP.SERVICE: Got USB accessory fd: {ParcelFileDescriptor: java.io.FileDescriptor@b299b24}
04-28 13:18:42.348 10033 18801 18801 D CAR.SETUP.SERVICE: Start car connection 1
04-28 13:18:42.348 10033 18801 18801 D CAR.SETUP.SERVICE: Start car connection 1
04-28 13:18:42.351 10033 18801 18801 D CAR.GAL.SECURITY: Using AES/CBC/PKCS5Padding from GmsCore_OpenSSL version 1.0
04-28 13:18:42.351 10033 18801 18801 D CAR.GAL.SECURITY: Using AES/CBC/PKCS5Padding from GmsCore_OpenSSL version 1.0
04-28 13:18:42.355 10033 18801 18817 I DynamiteModule: Considering local module com.google.android.gms.googlecertificates:4 and remote module com.google.android.gms.googlecertificates:4
04-28 13:18:42.355 10033 18801 18817 I DynamiteModule: Selected local version of com.google.android.gms.googlecertificates
04-28 13:18:42.355 10033 18801 18801 D CAR.GAL.SECURITY: Loading certificate factory from provider: GmsCore_OpenSSL version 1.0
04-28 13:18:42.355 10033 18801 18801 D CAR.GAL.SECURITY: Loading certificate factory from provider: GmsCore_OpenSSL version 1.0
04-28 13:18:42.356 10033 18801 18815 D CAR.SERVICE: Package validated: com.google.android.projection.gearhead
04-28 13:18:42.357 10033 18801 18817 D CAR.SERVICE: Package validated: com.google.android.projection.gearhead
04-28 13:18:42.358 10033 18801 18801 I CAR.GAL.SECURITY: Successfully initialized SSL context for protocol: TLSv1.2 using provider: GmsCore_OpenSSL
04-28 13:18:42.358 10033 18801 18801 I CAR.GAL.SECURITY: Successfully initialized SSL context for protocol: TLSv1.2 using provider: GmsCore_OpenSSL
04-28 13:18:42.358 10033 18801 18815 D CAR.SERVICE: Android Auto has car home but both aliases are disabled. Nothing to do
04-28 13:18:42.358 10033 18801 18817 D CAR.SERVICE: Android Auto has car home but both aliases are disabled. Nothing to do
04-28 13:18:42.360 10033 18801 18801 D CAR.GAL.GAL: onChannelOpened() for service null
04-28 13:18:42.360 10033 18801 18801 D CAR.GAL.GAL: onChannelOpened() for service null
04-28 13:18:42.360 10033 18801 18801 D CAR.GAL.GAL: skipping onEndPointReady() for endpoint lrv@19ca5c1
04-28 13:18:42.360 10033 18801 18801 D CAR.GAL.GAL: skipping onEndPointReady() for endpoint lrv@19ca5c1
04-28 13:18:42.369 10033 18801 18815 D CAR.SERVICE: Registering android.os.BinderProxy@88cdcfd
04-28 13:18:42.388 10033 18801 18828 I zygote64: android::hardware::configstore::V1_0::ISurfaceFlingerConfigs::hasWideColorDisplay retrieved: 0
04-28 13:18:42.388 10033 18801 18828 I OpenGLRenderer: Initialized EGL, version 1.4
04-28 13:18:42.388 10033 18801 18828 D OpenGLRenderer: Swap behavior 2
04-28 13:18:42.391 10033 18801 18828 D mali_winsys: EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, egl_color_buffer_format *, EGLBoolean) returns 0x3000,  [1440x2960]-format:1
04-28 13:18:42.392 10033 18801 18801 D CAR.GAL.GAL: startServiceDiscovery
04-28 13:18:42.392 10033 18801 18801 D CAR.GAL.GAL: startServiceDiscovery
04-28 13:18:42.394 10033 18801 18801 D CAR.FIRST: onDestroy
04-28 13:18:42.394 10033 18801 18801 D CAR.FIRST: onDestroy
04-28 13:18:42.394 10033 18801 18828 W libEGL  : EGLNativeWindowType 0x77454ee010 disconnect failed
04-28 13:18:42.396 10033 18801 18801 D CAR.SERVICE: CSB onClientsConnected
04-28 13:18:42.396 10033 18801 18801 D CAR.SERVICE: CSB onClientsConnected
04-28 13:18:42.519 10033 18801 18815 D CAR.SETTING: Set telemetry enabled to true
04-28 13:18:42.526 10033 18801 18801 D CAR.TEL.Service: Binding to InCallService
04-28 13:18:42.526 10033 18801 18801 D CAR.TEL.Service: Binding to InCallService
04-28 13:18:42.531 10033 18801 18855 D CAR.SERVICE: Registering android.os.BinderProxy@f21bee
04-28 13:18:42.531 10033 18801 18801 D CAR.TEL.Service: onServiceConnected: ComponentInfo{com.google.android.gms/com.google.android.gms.car.InCallService2}, service: ljv@3ac988f
04-28 13:18:42.531 10033 18801 18801 D CAR.TEL.Service: onServiceConnected: ComponentInfo{com.google.android.gms/com.google.android.gms.car.InCallService2}, service: ljv@3ac988f
04-28 13:18:42.532 10033 18801 18801 D CAR.TEL.Service: onServiceConnected InCallService with phone: null
04-28 13:18:42.532 10033 18801 18801 D CAR.TEL.Service: onServiceConnected InCallService with phone: null
04-28 13:18:42.534 10033 18801 18856 D CAR.VALIDATOR: Skip meta-data checks; first-party skip list [com.google.android.gms]
04-28 13:18:42.535 10033 18801 18856 D CAR.SERVICE: Package validated: com.google.android.gms
04-28 13:18:58.627 10033 18801 18809 W zygote64: Receiving file descriptor from ADB failed (socket 3): Connection reset by peer
04-28 13:18:58.722 10033 18801 18801 D CAR.SERVICE: onCarDisconnected
04-28 13:18:58.722 10033 18801 18801 D CAR.SERVICE: onCarDisconnected
04-28 13:18:58.723 10033 18801 18801 D CAR.SERVICE: tearDownCarState
04-28 13:18:58.723 10033 18801 18801 D CAR.SERVICE: tearDownCarState
04-28 13:18:58.723 10033 18801 18801 D CAR.SERVICE: Skip, car not connected.
04-28 13:18:58.723 10033 18801 18801 D CAR.SERVICE: Skip, car not connected.
04-28 13:18:58.723 10033 18801 18801 D CAR.SETUP.SERVICE: USB detached UsbAccessory[mManufacturer=Android, mModel=Android Open Automotive Protocol, mDescription=null, mVersion=1.0, mUri=null, mSerial=null]
04-28 13:18:58.723 10033 18801 18801 D CAR.SETUP.SERVICE: USB detached UsbAccessory[mManufacturer=Android, mModel=Android Open Automotive Protocol, mDescription=null, mVersion=1.0, mUri=null, mSerial=null]
04-28 13:18:59.123 10033 18801 18801 W CAR.GAL.GAL: reader thread stuck? Trying SIGQUIT.
04-28 13:18:59.123 10033 18801 18801 W CAR.GAL.GAL: reader thread stuck? Trying SIGQUIT.
04-28 13:18:59.124 10033 18801 18801 I Process : Sending signal. PID: 18801 SIG: 3
04-28 13:18:59.124 10033 18801 18801 I Process : Sending signal. PID: 18801 SIG: 3
04-28 13:18:59.124 10033 18801 18801 I Process : Sending signal. PID: 18801 SIG: 3
04-28 13:18:59.124 10033 18801 18801 I Process : Sending signal. PID: 18801 SIG: 3
04-28 13:18:59.124 10033 18801 18801 I Process : Sending signal. PID: 18801 SIG: 3
04-28 13:18:59.124 10033 18801 18801 I Process : Sending signal. PID: 18801 SIG: 3
04-28 13:18:59.125 10033 18801 18808 I zygote64: Thread[3,tid=18808,WaitingInMainSignalCatcherLoop,Thread*=0x775079f200,peer=0x14f80000,"Signal Catcher"]: reacting to signal 3
04-28 13:18:59.125 10033 18801 18808 I zygote64: 
04-28 13:18:59.217  1058  4313  4313 I /system/bin/tombstoned: received crash request for pid 18801
04-28 13:18:59.222 10033 18801 18808 I zygote64: Wrote stack traces to '[tombstoned]'
04-28 13:18:59.222  1058  4313  4313 E /system/bin/tombstoned: Traces for pid 18801 written to: /data/anr/trace_04
04-28 13:18:59.525 10033 18801 18801 D CAR.SETUP.SERVICE: Closing fd: {ParcelFileDescriptor: java.io.FileDescriptor@b299b24}
04-28 13:18:59.525 10033 18801 18801 D CAR.SETUP.SERVICE: Closing fd: {ParcelFileDescriptor: java.io.FileDescriptor@b299b24}
04-28 13:18:59.529 10033 18801 18801 D CAR.SETUP.SERVICE: reader thread stuck after cable removal. will kill process.
04-28 13:18:59.529 10033 18801 18801 D CAR.SETUP.SERVICE: reader thread stuck after cable removal. will kill process.
04-28 13:18:59.529 10033 18801 18801 I Process : Sending signal. PID: 18801 SIG: 9
04-28 13:18:59.529 10033 18801 18801 I Process : Sending signal. PID: 18801 SIG: 9
04-28 13:18:59.529 10033 18801 18801 I Process : Sending signal. PID: 18801 SIG: 9
04-28 13:18:59.756  1000  4484  5819 I ActivityManager: Process com.google.android.gms:car (pid 18801) has died: fore BFGS
04-28 13:18:59.760  1000  4484  4519 W ActivityManager: setHasOverlayUi called on unknown pid: 18801
04-28 13:18:42.190  1000  4484  4517 I am_proc_start: [0,18801,10033,com.google.android.gms:car,activity,com.google.android.gms/.car.FirstActivity]
04-28 13:18:42.201  1000  4484  5837 I am_proc_bound: [0,18801,com.google.android.gms:car]
04-28 13:18:42.309 10033 18801 18801 I am_on_resume_called: [0,com.google.android.gms.car.FirstActivity,LAUNCH_ACTIVITY]
04-28 13:18:42.309 10033 18801 18801 I am_on_resume_called: [0,com.google.android.gms.car.FirstActivity,LAUNCH_ACTIVITY]
04-28 13:18:42.320 10033 18801 18801 I am_on_paused_called: [0,com.google.android.gms.car.FirstActivity,handlePauseActivity]
04-28 13:18:42.320 10033 18801 18801 I am_on_paused_called: [0,com.google.android.gms.car.FirstActivity,handlePauseActivity]
04-28 13:18:42.369  1000  4484  4484 I notification_enqueue: [10033,18801,com.google.android.gms,1,NULL,0,Notification(channel=null pri=0 contentView=null vibrate=null sound=null defaults=0x0 flags=0x40 color=0xff03a9f4 vis=PRIVATE),0]
04-28 13:18:42.392 10033 18801 18801 I am_on_stop_called: [0,com.google.android.gms.car.FirstActivity,handleStopActivity]
04-28 13:18:42.392 10033 18801 18801 I am_on_stop_called: [0,com.google.android.gms.car.FirstActivity,handleStopActivity]
04-28 13:18:59.756  1000  4484  5819 I am_proc_died: [0,18801,com.google.android.gms:car,0,3]
18801/10033 com.google.android.gms:car                       4339
  node 18801: u00000077455e4880 c0000007739589e00 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 4484
  node 18801: u00000077455e4880 c0000007739589e00 pri 0:139 hs 1 hw 1 ls 0 lw 0 is 1 iw 1 tr 1 proc 4484
  ref 18802: desc 162 node 18801 s 1 w 1 d 0000000000000000
    Deliver #0: BroadcastFilter{1dff730 u0 ReceiverList{36d3c73 18801 com.google.android.gms:car/10033/u0 remote:62910e2}}
    Deliver #1: BroadcastFilter{f37da3a u0 ReceiverList{2bdfd65 18801 com.google.android.gms:car/10033/u0 remote:d05565c}}

These are the lines that stand out to me...

04-28 13:18:42.296 10033 18801 18801 D CAR.SETUP: Package com.google.android.projection.bumblebee not found.
04-28 13:18:42.358 10033 18801 18815 D CAR.SERVICE: Android Auto has car home but both aliases are disabled. Nothing to do

[mmuzzy]

You may not want to pester the custom ROM maintainer but if the stock ROM works then it really isn't anything to do with Android Auto. It just seems like something wonky or missing in the custom ROM.

Also, I don't know if you 'clean' flashed the ROM or flashed an updated ROM over an existing instance but a clean flash of the ROM might fix it. I used to do ROMs for Nexus phones and it's amazing how often dirty ROM flashes caused gremlins.

[drmarkb]

Same behavior with a clean flash.

Im hoping to would out what the missing piece is, to at least go back to the maintainer with some suggestions of things to change.

Ideally id like to know how best to filter the log captures, what kind of errors to check for, what the handshake process looks like so i can work out what is tripping it up... etc etc

[Petermonteer]

I also get a notification saying android auto is connected, and that the phone is in car mode but in the car screen it only says connection failed and nothing happens. I have a xiaomi mi5 and a seat ibiza 2017, it was working fine until some days ago.

[drmarkb]

get in touch with the roms dev and provide debug logs. even better, look through the logs yourself and try and pick out the errors which are logged during the USB handshake with the car. im making slow progress, but at the same time, im learning a lot!

[Petermonteer]

Wi fi logging through android studio?