[Nexus 6P Q&A, Help & Troubleshooting] dudbug:
Background:

We have our own Cisco Core/HSS/IMS, we create our own SIMs and have validated all registration services on all systems.

Problem:

We are down to one last and agonizing issue. We can't get our Nexus 6p phones to enable IMS. We have worked with our SIM vendor and have compared adb logs when using a TMO SIM and one of ours. The TMO sim sets ImsSenderRxr to enabled where as ours doesn't. I've heard that the default carrier config on the phone may be a problem. source.android.com/devices/tech/config/carrier.html#how_privilege_is_granted_to_a_carrier_app but our SIM vendor said that this shouldn't be the issue. Please find below the IMS portion of the adb logs from TMO and from our SIM:

TMO

08-04 16:08:41.149: D/ImsService AutoBoot(6358): Starting org.codeaurora.ims.ImsService : android.intent.action.SIM_STATE_CHANGED received.

08-04 16:08:41.155: E/ImsService AutoBoot(6358): org.codeaurora.ims.ImsService service Started Successfully

08-04 16:08:41.164: D/ImsService(4078): ImsService created!

08-04 16:08:41.169: D/ImsSenderRxr(4078): Starting IFMsg_Rxr[SUB0]

08-04 16:08:41.172: D/ImsSenderRxr(4078): Connecting to socket android.net.LocalSocket@aff77ce impl:android.net.LocalSocketImpl@c9af6ef fd:FileDescriptor[58]

08-04 16:08:41.172: I/ImsSenderRxr(4078): Connected to 'android.net.LocalSocket@aff77ce impl:android.net.LocalSocketImpl@c9af6ef fd:FileDescriptor[58]' socket

08-04 16:08:41.172: I/ImsSenderRxr(4078): For instance [0] connected to 'qmux_radio/rild_ims0' socket

08-04 16:08:41.172: V/ImsSenderRxr(4078): Read packet: 15 bytes

08-04 16:08:41.173: V/ImsSenderRxr(4078): processResponse[SUB0]

08-04 16:08:41.173: D/ImsSenderRxr(4078): Response data: [12, 13, -1, -1, -1, -1, 16, 3, 24, -43, 1, 32, 0, 8, 10][SUB0]

08-04 16:08:41.178: D/ImsConfigImpl(4078): Video calls are disabled by carrier config.

08-04 16:08:41.178: D/ImsConfigImpl(4078): Video call feature is disabled

08-04 16:08:41.179: D/ImsConfigImpl(4078): setServiceStatus = 3 14 0

08-04 16:08:41.180: D/ImsSenderRxr(4078): Tag -1 3 213 0[SUB0]

08-04 16:08:41.181: D/ImsSenderRxr(4078): [0000]> REQUEST_SET_SERVICE_STATUS[SUB0][/B][/U]

08-04 16:08:41.181: D/ImsSenderRxr(4078): Message data: [0, 0, 0, 27, 11, 13, 0, 0, 0, 0, 16, 1, 24, 30, 32, 0, 8, 1, 24, 3, 58, 9, 8, 14, 16, 0, 29, 0, 0, 0, 0][SUB0]

08-04 16:08:41.183: I/ActivityManager(917): Start proc 6379:com.android.cellbroadcastreceiver/u0a4 for broadcast com.android.cellbroadcastreceiver/.CellBroadcastReceiver

08-04 16:08:41.184: D/ImsConfigImpl(4078): setServiceStatus = 3 19 0

08-04 16:08:41.184: D/ImsSenderRxr(4078): [0001]> REQUEST_SET_SERVICE_STATUS[SUB0]

08-04 16:08:41.184: D/ImsSenderRxr(4078): Message data: [0, 0, 0, 27, 11, 13, 1, 0, 0, 0, 16, 1, 24, 30, 32, 0, 8, 1, 24, 3, 58, 9, 8, 19, 16, 0, 29, 0, 0, 0, 0][SUB0]

08-04 16:08:41.186: D/ImsSenderRxr(4078): [0002]> REQUEST_QUERY_SERVICE_STATUS[SUB0]

08-04 16:08:41.187: D/ImsSenderRxr(4078): Message data: [0, 0, 0, 12, 11, 13, 2, 0, 0, 0, 16, 1, 24, 29, 32, 0][SUB0]

08-04 16:08:41.188: V/ImsSenderRxr(4078): Read packet: 12 bytes

08-04 16:08:41.188: V/ImsSenderRxr(4078): processResponse[SUB0]

08-04 16:08:41.188: D/ImsSenderRxr(4078): Response data: [11, 13, 0, 0, 0, 0, 16, 2, 24, 30, 32, 0][SUB0]

08-04 16:08:41.188: D/ImsSenderRxr(4078): Tag 0 2 30 0[SUB0]

08-04 16:08:41.188: D/ImsSenderRxr(4078): [0000]< REQUEST_SET_SERVICE_STATUS [SUB0]

08-04 16:08:41.189: V/ImsSenderRxr(4078): Read packet: 76 bytes

08-04 16:08:41.189: D/ImsConfigImpl(4078): Message received: what = 3

08-04 16:08:41.189: V/ImsSenderRxr(4078): processResponse[SUB0]

08-04 16:08:41.189: D/ImsSenderRxr(4078): Response data: [11, 13, 2, 0, 0, 0, 16, 2, 24, 29, 32, 0, 18, 14, 8, 1, 24, 0, 58, 8, 8, 18, 16, 0, 34, 2, 8, 2, 18, 14, 8, 1, 24, 3, 58, 8, 8, 18, 16, 0, 34, 2, 8, 2, 18, 14, 8, 1, 24, 1, 58, 8, 8, 18, 16, 0, 34, 2, 8, 2, 18, 14, 8, 1, 24, 2, 58, 8, 8, 18, 16, 0, 34, 2, 8, 2][SUB0]

08-04 16:08:41.189: D/ImsSenderRxr(4078): Tag 2 2 29 0[SUB0]

08-04 16:08:41.189: E/ImsConfigImpl(4078): getImsConfigListener returns null

08-04 16:08:41.189: E/ImsConfigImpl(4078): onSetFeatureResponseDone listener is not valid !!!

08-04 16:08:41.189: D/ImsSenderRxr(4078): isValid = true type = 0 status = 0 userdata = null[SUB0]

08-04 16:08:41.190: D/ImsSenderRxr(4078): networkMode = 18 status = 0 restrictCause = 0 registered = 2[SUB0]

08-04 16:08:41.190: D/ImsSenderRxr(4078): isValid = true type = 3 status = 0 userdata = null[SUB0]

08-04 16:08:41.190: D/ImsSenderRxr(4078): networkMode = 18 status = 0 restrictCause = 0 registered = 2[SUB0]

08-04 16:08:41.190: D/ImsSenderRxr(4078): isValid = true type = 1 status = 0 userdata = null[SUB0]

08-04 16:08:41.190: D/ImsSenderRxr(4078): networkMode = 18 status = 0 restrictCause = 0 registered = 2[SUB0]

08-04 16:08:41.190: D/ImsSenderRxr(4078): isValid = true type = 2 status = 0 userdata = null[SUB0]

08-04 16:08:41.190: D/ImsSenderRxr(4078): networkMode = 18 status = 0 restrictCause = 0 registered = 2[SUB0]

08-04 16:08:41.190: D/ImsSenderRxr(4078): [0002]< REQUEST_QUERY_SERVICE_STATUS [org.codeaurora.ims.ServiceStatus@11225fc, org.codeaurora.ims.ServiceStatus@9352485, org.codeaurora.ims.ServiceStatus@9f42da, org.codeaurora.ims.ServiceStatus@8ca130b][SUB0]

08-04 16:08:41.190: V/ImsSenderRxr(4078): Read packet: 12 bytes

08-04 16:08:41.190: V/ImsSenderRxr(4078): processResponse[SUB0]

08-04 16:08:41.190: D/ImsSenderRxr(4078): Response data: [11, 13, 1, 0, 0, 0, 16, 2, 24, 30, 32, 0][SUB0]

08-04 16:08:41.191: D/ImsSenderRxr(4078): Tag 1 2 30 0[SUB0]

08-04 16:08:41.191: D/ImsSenderRxr(4078): [0001]< REQUEST_SET_SERVICE_STATUS [SUB0]

08-04 16:08:41.191: D/ImsConfigImpl(4078): Message received: what = 3

08-04 16:08:41.191: E/ImsConfigImpl(4078): getImsConfigListener returns null

08-04 16:08:41.191: E/ImsConfigImpl(4078): onSetFeatureResponseDone listener is not valid !!!

From our SIM:

08-04 16:01:00.458: D/ImsService AutoBoot(4849): Starting org.codeaurora.ims.ImsService : android.intent.action.SIM_STATE_CHANGED received.

08-04 16:01:00.461: E/ImsService AutoBoot(4849): org.codeaurora.ims.ImsService service Started Successfully

08-04 16:01:00.471: D/ImsService(3644): ImsService created!

08-04 16:01:00.477: D/ImsSenderRxr(3644): Starting IFMsg_Rxr[SUB0]

08-04 16:01:00.478: I/ActivityManager(914): Start proc 4861:com.android.cellbroadcastreceiver/u0a4 for broadcast com.android.cellbroadcastreceiver/.CellBroadcastReceiver

08-04 16:01:00.480: D/ImsSenderRxr(3644): Connecting to socket android.net.LocalSocket@1f0de00 impl:android.net.LocalSocketImpl@b32b639 fd:FileDescriptor[58]

08-04 16:01:00.481: I/ImsSenderRxr(3644): Connected to 'android.net.LocalSocket@1f0de00 impl:android.net.LocalSocketImpl@b32b639 fd:FileDescriptor[58]' socket

08-04 16:01:00.481: I/ImsSenderRxr(3644): For instance [0] connected to 'qmux_radio/rild_ims0' socket

08-04 16:01:00.481: V/ImsSenderRxr(3644): Read packet: 15 bytes

08-04 16:01:00.481: V/ImsSenderRxr(3644): processResponse[SUB0]

08-04 16:01:00.482: D/ImsSenderRxr(3644): Response data: [12, 13, -1, -1, -1, -1, 16, 3, 24, -43, 1, 32, 0, 8, 10][SUB0]

08-04 16:01:00.485: D/ImsConfigImpl(3644): Video calls are disabled by carrier config.

08-04 16:01:00.486: D/ImsSenderRxr(3644): Tag -1 3 213 0[SUB0]

08-04 16:01:00.487: D/ImsConfigImpl(3644): Video call feature is disabled

08-04 16:01:00.488: D/ImsConfigImpl(3644): setServiceStatus = 3 14 0

08-04 16:01:00.489: D/ImsSenderRxr(3644): [0000]> REQUEST_SET_SERVICE_STATUS[SUB0]

08-04 16:01:00.489: D/ImsSenderRxr(3644): Message data: [0, 0, 0, 27, 11, 13, 0, 0, 0, 0, 16, 1, 24, 30, 32, 0, 8, 1, 24, 3, 58, 9, 8, 14, 16, 0, 29, 0, 0, 0, 0][SUB0]

08-04 16:01:00.491: D/ImsConfigImpl(3644): setServiceStatus = 3 19 0

08-04 16:01:00.492: D/ImsSenderRxr(3644): [0001]> REQUEST_SET_SERVICE_STATUS[SUB0]

08-04 16:01:00.492: D/ImsSenderRxr(3644): Message data: [0, 0, 0, 27, 11, 13, 1, 0, 0, 0, 16, 1, 24, 30, 32, 0, 8, 1, 24, 3, 58, 9, 8, 19, 16, 0, 29, 0, 0, 0, 0][SUB0]

08-04 16:01:00.493: D/ImsSenderRxr(3644): [0002]> REQUEST_QUERY_SERVICE_STATUS[SUB0]

08-04 16:01:00.493: D/ImsSenderRxr(3644): Message data: [0, 0, 0, 12, 11, 13, 2, 0, 0, 0, 16, 1, 24, 29, 32, 0][SUB0]

08-04 16:01:00.509: D/ConnectivityService(914): notifyType CAP_CHANGED for NetworkAgentInfo [WIFI () - 101]

08-04 16:01:00.514: D/(3644): jint JNI_OnLoad(JavaVM*, void*)

08-04 16:01:00.514: D/(3644): JvmPtr initialized to -1378037440

08-04 16:01:00.514: D/ims_media_jni(3644): int register_ims_media(JNIEnv*)

08-04 16:01:00.518: V/ImsSenderRxr(3644): Read packet: 12 bytes

08-04 16:01:00.518: V/ImsSenderRxr(3644): processResponse[SUB0]

08-04 16:01:00.518: D/ImsSenderRxr(3644): Response data: [11, 13, 0, 0, 0, 0, 16, 2, 24, 30, 32, 2][SUB0]

08-04 16:01:00.519: D/ImsSenderRxr(3644): Tag 0 2 30 2[SUB0]

08-04 16:01:00.519: D/ImsSenderRxr(3644): [0000]< REQUEST_SET_SERVICE_STATUS error: 2

08-04 16:01:00.519: V/ImsSenderRxr(3644): Read packet: 12 bytes

08-04 16:01:00.519: D/ImsConfigImpl(3644): Message received: what = 3

08-04 16:01:00.519: V/ImsSenderRxr(3644): processResponse[SUB0]

08-04 16:01:00.519: D/ImsSenderRxr(3644): Response data: [11, 13, 1, 0, 0, 0, 16, 2, 24, 30, 32, 2][SUB0]

08-04 16:01:00.519: D/ImsSenderRxr(3644): Tag 1 2 30 2[SUB0]

08-04 16:01:00.519: E/ImsConfigImpl(3644): getImsConfigListener returns null

08-04 16:01:00.519: D/ImsSenderRxr(3644): [0001]< REQUEST_SET_SERVICE_STATUS error: 2

08-04 16:01:00.519: E/ImsConfigImpl(3644): onSetFeatureResponseDone listener is not valid !!!

I'm hoping someone can help point me in the correct direction.... I suspect it surrounds the line that says 08-04 16:01:00.519: D/ImsSenderRxr(3644): [0001]< REQUEST_SET_SERVICE_STATUS error: 2...but I'm not sure.

Thanks

Jake