- はじめに
- APNs 通知の仕組みと目的
- APNs が動作するための前提事項
- APNs・iPhone の要件
- WLAN 利用の場合：NAT タイマー
- Jabber, Unified CM のバージョン
- Unified CM の Cloud Onboarding 有効化
- APNs が Jabber で受信されるまでのログ
- ログ調査における識別子
- サインイン: Device Token の共有
- Jabber for iPhone
- Unified CM: User Data Service (UDS)
- Unified CM: Cisco CallManager
- バックグラウンド着信
- Unified CM: Cisco CallManager
- Unified CM: Cisco Push Notification Service (CPNS)
- Jabber for iPhone
- サインアウト: Device Token の削除
- Jabber for iPhone
- Unified CM: User Data Service (UDS)
- Unified CM: Cisco CallManager
- トラブルシューティングに有効なコマンド
- Unified CM: Token の確認
- 2021-08-26 14:19:27 にサインアウトした後の DB
- 2021-08-31 18:45:25 にサインインした後の DB
- 2021-08-31 18:46:15 にアプリをスワイプで終了し再度起動した際の DB
- Unified CM: Cisco Cloud への疎通性の確認
- 発生する問題例とトラブルシューティング方法
- プッシュが遅延して届く
- Jabber がバックグラウンドの際に着信が出来ない
- 着信を受話しても無音となり、該当コールが着信履歴に残らない
- Cisco TAC にケースを上げる際に必要な情報
- 参考情報
はじめに
本ドキュメントでは、 Jabber for iPhone において Apple Push Notification service (APNs) から Push 通知が届かない際のトラブルシューティングについて紹介します。APNs が受信できない場合、以下のような問題が生じる可能性があります。
- Jabber が起動していない際 (スワイプでタスクキルされた際) に着信が出来ない。
- iPhone がスリープ状態の際に着信が出来ない。
- Jabber がバックグラウンド時に着信が出来ない。
APNs 通知の仕組みと目的
Jabber for iPhone では IP Phone とは異なり必ずしも常時起動しているとは限りません。例えばユーザーがスワイプにより Jabber アプリを終了させた場合や、iOS 側に終了させられた場合は Unified CM への REGISTER が外れた状況となります。このような状況下でも着信を行うために Apple Push Notification Service (APNs) が利用されます。
APNs を利用することで、Jabber が起動していない場合でも Unified CM は Apple のサーバーを経由して iOS に Push 通知を送信し、Push を受けた iOS は Jabber を起動します。その後 Jabber は Unified CM へ REGISTER を行い、INVITE (着信) を受信します。
以下では各コンポーネントの実際のログを確認しながら、Push が Jabber に届くまでの過程を説明します。
なお、APNs のフロー詳細については以下のドキュメントも併せてご確認ください。
APNs が動作するための前提事項
APNs に問題がある場合はまずは以下のドキュメントで要件を満たしているか、設定に不備がないかご確認ください。
APNs・iPhone の要件
以下、Apple の APNs 要件に関するドキュメントとなります。Firewall 等で Push がブロックされていないかご確認ください。
WLAN 利用の場合：NAT タイマー
以下、WLAN 環境（非 LTE環境）で Jabber を利用する場合の NAT タイマーに関する注意事項となります。
Jabber, Unified CM のバージョン
Jabber for iPhone で APNs を利用するためには以下のドキュメントのバージョン要件を満たしている必要があります。
Unified CM の Cloud Onboarding 有効化
全ての端末にて Push が着信できない場合、Unified CM の Cloud Onboarding 設定が適切に行われていない可能性があります。下記ドキュメントを参考に Unified CM Admin > Advanced Features > Cisco Cloud Onboarding の設定が有効であるか確認を行ってください。
また、Cisco Unified Serviceability > Tools > Control Center - Network Services から Cisco Push Notification Service が起動していることも確認してください。
APNs が Jabber で受信されるまでのログ
以下では実際のバックグラウンド着信時のログを用いて、Jabber が Push 通知を受けるまでの流れを説明します。実際のトラブルシューティングでは、これらのログを確認しながら、どの段階で Push が機能していないかを調査していく流れになります。
なお、今回のドキュメントでは Unified CM と Jabber でログ上でに2秒ほどのずれがあり、Jabber 側のログが時間が進んでいます。
ログ調査における識別子
APNs のプッシュに関する調査の際は以下の識別子を用いながら調査を行います。
- CI (Call Identifier): コール単位で発信側・着信側に付与され、コールログから確認が出来ます。詳細については CUCM のコールログ (calllogs*.txt) のフォーマット もご確認ください。
- Push ID: <node-ID>-<着信側 CI> で構成され、Unified CM, Jabber ログにて Push に関する動作が行われる際に本識別子がログから確認できます。
- Tracking ID: Unified CM, Cisco Cloud, Jabber すべてのログにて確認できる Push リクエスト単位で付与される識別子です。Cisco Cloud 側の調査が必要な場合は TAC にて Tracking ID がログから確認できる必要があります。
- Device ID : Unified CM の DB 内でデバイスごとに一意に存在する ID となります。後述の下記コマンドにより特定のデバイスの ID を特定することが出来ます。
run sql SELECT dev.name, token.*, DBINFO('utc_to_datetime', token.cdrtime) as last_update FROM device as dev INNER JOIN devicetokendynamic as token ON dev.pkid in (token.pkid, token.fkdevice) WHERE dev.name = '<Device Name>'
これらをログ中で確認をしながら解析を進めるためには、後述の Cisco TAC にケースオープンする際に必要な情報に記載のあるログが必要となります。
サインイン: Device Token の共有
Jabber がサインインしている状態の時は、Unified CM で保持される Device Token を最新の状態に保つため、Jabber が起動されるたびに Unified CM へ Device Token が送信されます。この Device token は APNs が Push を送信する iPhone デバイスを識別するために必要となります。
Jabber for iPhone
サインイン・起動時に Jabber は Device token を Unified CM に送信します。太字のように Device ID や Device token がログから確認できます。図中 ① に相当します。
2021-08-24 13:56:26,205 INFO [0x000000016ede7000] [lcontrol/CallControlManagerImpl.cpp(779)] [csf.ecc] [setVoicePushDeviceTokenV2] - deviceId=4f4e7dd4-07b2-c145-6aac-4c8ddc382de9,voicepushDeviceToken=01d84a2520d6560567e7c03e1b7e30d97969d9a8cda347096b829cd71f06ca4b,aes_key=b-a8LYvi6owHWhrqBDOEUXPoocK-jzSG2NmGA_NOZbA,algo=A256GCM,application=jabber,version supported=V2,additional= 2021-08-24 13:56:26,205 INFO [0x000000016ede7000] [nts/ecc/src/config/UDSRetriever.cpp(260)] [csf.ecc] [setDeviceTokenV2] - setDeviceToken 2021-08-24 13:56:26,205 DEBUG [0x000000016ede7000] [onents/ecc/src/config/UDSClient.cpp(386)] [csf.ecc] [setDeviceTokenV2] - set device token url=https://dmz-cucm1.collabdmz.lab:8443/cucm-uds/user/yanzai/device/4f4e7dd4-07b2-c145-6aac-4c8ddc382de9/devicetoken 2021-08-24 13:56:26,205 DEBUG [0x000000016ede7000] [onents/ecc/src/config/UDSClient.cpp(387)] [csf.ecc] [setDeviceTokenV2] - set device token data=<token><pushNotifyToken>01d84a2520d6560567e7c03e1b7e30d97969d9a8cda347096b829cd71f06ca4b</pushNotifyToken><pushChannelType>APNS</pushChannelType><key>b-a8LYvi6owHWhrqBDOEUXPoocK-jzSG2NmGA_NOZbA</key><algorithm>A256GCM</algorithm><application>jabber</application><payloadVersion>V2</payloadVersion></token>
Unified CM: User Data Service (UDS)
Unified CM の UDS は Jabber から HTTP リクエストを受け取り DB 内のdevicetokendynamic テーブルを更新します。太字のように Device ID がログから確認できます。図中 ① および 図中 ② に相当します。
2021-08-24 13:56:24,630 DEBUG [http-nio-1027-exec-14] security.ThrottleFilter - Requested URI: /cucm-uds/user/yanzai/device/4f4e7dd4-07b2-c145-6aac-4c8ddc382de9/devicetoken over the port 8443 2021-08-24 13:56:24,631 DEBUG [http-nio-1027-exec-14] security.ThrottleFilter - Allowing request. #req/#allowed: 1/50 2021-08-24 13:56:24,631 DEBUG [http-nio-1027-exec-14] security.CNThrottleFilter - doFilter 2021-08-24 13:56:24,631 DEBUG [http-nio-1027-exec-14] security.CNThrottleFilter - HttpMethod PUT; checking CNThrottle 2021-08-24 13:56:24,634 DEBUG [http-nio-1027-exec-14] services.DeviceService - Retrieved cached device list for userId 'yanzai' 2021-08-24 13:56:24,635 DEBUG [http-nio-1027-exec-14] services.TokenService - SELECT pkid FROM Enduser WHERE userid = ? 2021-08-24 13:56:24,637 DEBUG [http-nio-1027-exec-14] services.TokenService - UPDATE deviceTokenDynamic SET pushnotifytoken = ? ,pushchanneltype = ? ,key = ? ,algorithm = ? ,application = ? ,payloadversion = ? ,devicetoken = ? ,iscallkitdisabled = ? ,fkenduser = ? WHERE fkdevice = ? 2021-08-24 13:56:24,646 DEBUG [http-nio-1027-exec-14] services.TokenService - rows updated with token1 2021-08-24 13:56:24,647 DEBUG [http-nio-1027-exec-14] security.ThrottleFilter - Request: PUT /user/yanzai/device/4f4e7dd4-07b2-c145-6aac-4c8ddc382de9/devicetoken completed in: 17ms
Unified CM: Cisco CallManager
Device token に関する DB テーブル (devicetokendynamic) が更新され CallManager 内の該当 Jabber の LineControl プロセスに DB の更新を通知します。すでに Device token が DB に存在し、アップデート前後に変化がない場合はこの通知は発生しません。太字のように Device ID や該当デバイスの LineControl プロセスがログから確認できます。
12662289.000 |13:56:24.747 |SdlSig |CcmDbTableChangeNotify |wait |CcmDbChangeNotify(1,100,223,1) |CcmDbChangeNotify(1,100,223,1) |1,100,223,1.1395^*^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] 12662289.001 |13:56:24.747 |AppInfo |DB: SQL1[select * from devicetokendynamic where pkid = '4f4e7dd4-07b2-c145-6aac-4c8ddc382de9';] 12662289.002 |13:56:24.749 |AppInfo |DB: SQL2[select * from devicetokendynamic where pkid = '4f4e7dd4-07b2-c145-6aac-4c8ddc382de9';] 12662289.003 |13:56:24.750 |AppInfo |SMDMSharedData::findLocalDevice - Name=2104: Key=da01ccc5-a723-c4c4-0994-f03db7e2c3f9 isActvie=1 Pid=(1,85,11) found 12662290.000 |13:56:24.750 |SdlSig |DmPushNotifyUpdate |restart0 |LineControl(1,100,85,11) |DeviceManager(1,100,53,1) |1,100,223,1.1395^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] devicePkid: 4f4e7dd4-07b2-c145-6aac-4c8ddc382de9
以上で Device token の同期は終了しました。この Token を用いて Unified CM は実際に Jabber に着信をさせたい場面に Cisco Cloud 経由で APNs までリクエストを行います。
バックグラウンド着信
以下では実際に Jabber for iPhone に着信を行う際の Push 通知のフローを説明します。全体の流れは以下の画像のように Callmanager -> Cisco Push Notification Service -> Cisco Collaboration Cloud -> APNs -> Jabber の順にリクエストが送信されます。
Unified CM: Cisco CallManager
LineControl プロセスから CPNS に Push 送信をリクエストします。なお、発信側デバイスと着信側デバイスのノードが異なる場合は着信側 (Jabber デバイス登録側) ノードがこの処理を行います。リクエストには Tracking ID や Push ID が含まれていることが確認できます。
以下はリクエストログとなり、図中 ① に相当します。
12662456.000 |13:56:33.642 |SdlSig |SsPushNotifyReq |wait |PushNotifyManager(1,100,221,1) |LineControl(1,100,85,11) |1,100,251,43906.17^10.70.89.138^CSFYANZAI |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI=21292822 CI.branch=0 aeInfo.sendingDchan=[1, 100, 85, 11] devPkid=4f4e7dd4-07b2-c145-6aac-4c8ddc382de9 pushNotificationType=1 failoverData= activeCucm=dmz-cucm1.collabdmz.lab 12662457.002 |13:56:33.643 |AppInfo |PushNotify::wait_SsPushNotifyReq() Sending PNReq for trackingID = CUCMCallP_82cacae7-8d8c-416b-a477-6972f52f42fb_deploy:onprem_clusterinfo:StandAloneCluster-1, pushId = 1-21292822
リクエスト完了後、CPNS から正常にレスポンスが返答されていることが確認できます(pushNotifyRes=1) 以下ログは 図中 ⑥ に相当します。
12662520.000 |13:56:35.197 |SdlSig |SsPushNotifyRes |restart0 |LineControl(1,100,85,11) |PushNotify(1,100,222,14) |1,100,251,43876.4^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] CI=21292822 CI.branch=0 aeInfo.sendingDchan=[1, 100, 85, 11] devPkid=4f4e7dd4-07b2-c145-6aac-4c8ddc382de9 pushNotifyRes=1
Unified CM: Cisco Push Notification Service (CPNS)
CallManager サービスから Push 送信リクエストを受信し、処理を行う (図中 ①)
### rcv req from ccm
2021-08-24 13:56:33,644 DEBUG [com.cisco.ccm.ccmpns.CCMPNSClientConnectionHandler@1df8190 ReceiveThread] ccmpns.MonitorThread (MonitorThread.java:26) - queueMessage() message :{"MESSAGETYPE":"REQUEST_PUSH_NOTIFICATION","TYPE":"incomingcall","PUSHID":"1-21292822","ACTIVECUCM":"dmz-cucm1.collabdmz.lab","DEVICETOKEN":"01d84a2520d6560567e7c03e1b7e30d97969d9a8cda347096b829cd71f06ca4b","KEY":"b-a8LYvi6owHWhrqBDOEUXPoocK-jzSG2NmGA_NOZbA","ALGO":"A256GCM","CHANNEL":"APNS","TRACKINGID":"CUCMCallP_82cacae7-8d8c-416b-a477-6972f52f42fb_deploy:onprem_clusterinfo:StandAloneCluster-1","APPLICATION":"jabber","PAYLOADVERSION":"V2","DISPLAYNAME":"","DISPLAYNUMBER":"yanzai@collabdmz.lab","HUNTPILOTDN":"","RINGEXPIRETIME":"","PUSHTYPE":"voip"}
### process
2021-08-24 13:56:33,646 INFO [pool-16-thread-1] ccmpns.WorkerThread (WorkerThread.java:105) - run() PushRequest received :{"MESSAGETYPE":"REQUEST_PUSH_NOTIFICATION","TYPE":"incomingcall","PUSHID":"1-21292822","ACTIVECUCM":"dmz-cucm1.collabdmz.lab","DEVICETOKEN":"01d84a2520d6560567e7c03e1b7e30d97969d9a8cda347096b829cd71f06ca4b","KEY":"b-a8LYvi6owHWhrqBDOEUXPoocK-jzSG2NmGA_NOZbA","ALGO":"A256GCM","CHANNEL":"APNS","TRACKINGID":"CUCMCallP_82cacae7-8d8c-416b-a477-6972f52f42fb_deploy:onprem_clusterinfo:StandAloneCluster-1","APPLICATION":"jabber","PAYLOADVERSION":"V2","DISPLAYNAME":"","DISPLAYNUMBER":"yanzai@collabdmz.lab","HUNTPILOTDN":"","RINGEXPIRETIME":"","PUSHTYPE":"voip"}
Cisco Collaboration Cloud に Push を送信 (図中 ②)
### push to cloud
2021-08-24 13:56:33,648 INFO [pool-16-thread-1] ccmpns.WorkerThread (WorkerThread.java:275) - WorkerThread Host : push.webexconnect.com
2021-08-24 13:56:33,648 INFO [pool-16-thread-1] ccmpns.WorkerThread (WorkerThread.java:301) - handlePushNotificatonRequest() PUSHID: 1-21292822
2021-08-24 13:56:33,648 DEBUG [pool-16-thread-1] ccmpns.WorkerThread (WorkerThread.java:302) - handlePushNotificatonRequest() POST BODY: {"app":"jabber","service":"apns","channel":"prod","target":"####","type":"voip","sender":"CUCM-12.5.1.14900-63","payload":"####"}
APNs から 200OK を受信 (図中 ⑤, ⑥)
### response from cloud
2021-08-24 13:56:35,196 INFO [pool-16-thread-1] ccmpns.WorkerThread (WorkerThread.java:325) - handlePushNotificatonRequest() Response received : 200 Text: PUSHID : 1-21292822
2021-08-24 13:56:35,196 DEBUG [pool-16-thread-1] ccmpns.PushVoiceClientPool (PushVoiceClientPool.java:312) - createClientPool() Skip Proxy retry since no hostname is configured
2021-08-24 13:56:35,196 INFO [pool-16-thread-1] ccmpns.WorkerThread (WorkerThread.java:341) - handlePushNotificatonRequest() Response to client{"MESSAGETYPE":"RESPONSE_PUSH_NOTIFICATION","TRACKINGID":"CUCMCallP_82cacae7-8d8c-416b-a477-6972f52f42fb_deploy:onprem_clusterinfo:StandAloneCluster-1","STATUS":"200","TEXT":""} Push ID :1-21292822
200OK 以外の Response に関しては以下ドキュメントも併せてご確認ください。
Jabber for iPhone
APNs サーバーから iOS が Push を受け取り、iOS が Jabber を起動させます。これらのログには Tracking ID や Push ID が含まれます。
021-08-24 13:56:37,623 DEBUG [0x000000010932b8c0] [hone/app/ManU/Classes/AppDelegate.m(320)] [UI.Action.System] [-[JabberIOSAppDelegate application:didFinishLaunchingWithOptions:]] - iOS system(not user) launch jabber at background
2021-08-24 13:56:37,645 INFO [0x000000010932b8c0] [tahiti/ui/APNS/YLCVoipPushManager.m(287)] [UI.Action.System] [-[YLCVoipPushManager pushRegistry:didReceiveIncomingPushWithPayload:forType:withCompletionHandler:]] - jabber receive push message. payload.type:PKPushTypeVoIP, for type: PKPushTypeVoIP, Cisco-Tracking-ID: CUCMCallP_82cacae7-8d8c-416b-a477-6972f52f42fb_deploy:onprem_clusterinfo:StandAloneCluster-1, teams-trackingId:(null)
2021-08-24 13:56:37,647 DEBUG [0x000000010932b8c0] [lSecureDataKeyChainStorageHelper.mm(210)] [UI.PushKitCall] [processVoicePushMessage] - received voice push message {"type":"incomingcall","pushid":"1-21292822","activecucm":"dmz-cucm1.collabdmz.lab","displayname":"","displaynumber":"yanzai@collabdmz.lab","payloadversion":"V2","huntpilotdn":"","ringexpiretime":""}
2021-08-24 13:56:37,647 DEBUG [0x000000010932b8c0] [lSecureDataKeyChainStorageHelper.mm(246)] [UI.PushKitCall] [processVoicePushMessage] - processVoicePushMessage type:incomingcall,pushId: ,displayName: 1-21292822,displayNumber: yanzai@collabdmz.lab,huntPilotDn: ,ringexpiretime:
2021-08-24 13:56:37,647 INFO [0x000000010932b8c0] [tahiti/ui/APNS/YLCVoipPushManager.m(456)] [UI.APNS] [-[YLCVoipPushManager pushRegistry:didReceiveIncomingPushWithPayload:forType:withCompletionHandler:]] - create new pushKit call to callKit (pushId:1-21292822)
その後 Unified CM は Jabber から REGISTER message を受信した後 INVITE を送信します。この INVITE には Push ID が含まれるため、Jabber 側は先行して受信した APNs プッシュと INVITE コールを対応付けることが出来ます。以下 SIP messageは一部省略しています。
Jabber -> Unified CM : REGISTER
2021-08-24 13:56:39,385 DEBUG [0x000000016fb93000] [/sipcc/core/sipstack/ccsip_debug.c(1735)] [csf.sip-call-control] [platform_print_sip_msg] - sipio-sent---> REGISTER sip:dmz-cucm1.collabdmz.lab SIP/2.0 From: <sip:2104@dmz-cucm1.collabdmz.lab>;tag=2cdd428bf1230003513d42e1-0cf1eb72 To: <sip:2104@dmz-cucm1.collabdmz.lab> Call-ID: 2cdd428b-f1230002-406707f0-2c3a3e98@192.168.12.6 Max-Forwards: 70 Date: Tue, 24 Aug 2021 04:56:39 GMT CSeq: 103 REGISTER User-Agent: Cisco-TCT Expires: 720 Content-Length: 0
Unified CM -> Jabber : 200 OK (REGISTER)
2021-08-24 13:56:39,413 DEBUG [0x000000016fb93000] [/sipcc/core/sipstack/ccsip_debug.c(1735)] [csf.sip-call-control] [platform_print_sip_msg] - sipio-recv<--- SIP/2.0 200 OK Call-ID: 2cdd428b-f1230002-406707f0-2c3a3e98@192.168.12.6 CSeq: 103 REGISTER Contact: <sip:f4399658-4057-68a1-0e94-80fe347b5ad1@192.168.12.6:57961;transport=tls;orig-hostport=192.168.12.6:57961>;+sip.instance="<urn:uuid:00000000-0000-0000-0000-2cdd428bf123>";+u.sip!devicename.ccm.cisco.com="TCTYANZAI";+u.sip!model.ccm.cisco.com="562";+u.sip!mtpreferredmode.ccm.cisco.com="voip";sip.ice;video;bfcp;x-cisco-mra-ha=AR_SK;x-cisco-reg-id=1 From: <sip:2104@dmz-cucm1.collabdmz.lab>;tag=2cdd428bf1230003513d42e1-0cf1eb72 To: <sip:2104@dmz-cucm1.collabdmz.lab>;tag=417211625 Server: Cisco-CUCM12.5 Expires: 720 Date: Tue, 24 Aug 2021 04:56:37 GMT Supported: X-cisco-voicepush-enabled,X-cisco-srtp-fallback,X-cisco-sis-9.2.0 Session-ID: 0d2aa34a00255000a0000538878d0000;remote=0675bd8f00255000a00001898ee30000 Content-Length: 0
Unified CM -> Jabber : INVITE (Push ID を含む)
2021-08-24 13:56:39,461 DEBUG [0x000000016fb93000] [/sipcc/core/sipstack/ccsip_debug.c(1735)] [csf.sip-call-control] [platform_print_sip_msg] - sipio-recv<--- INVITE sip:f4399658-4057-68a1-0e94-80fe347b5ad1@192.168.12.6 SIP/2.0 Call-ID: a82a3600-1ed1229a-2f0d9-99e6470a@10.71.230.153 CSeq: 101 INVITE Call-Info: <urn:x-cisco-remotecc:callinfo>;security=Unknown;orientation=from;gci=1-3029;pushId=1-21292822;isVoip;call-instance=1 Remote-Party-ID: <sip:yanzai@collabdmz.lab;x-cisco-number=2004;x-cisco-callback-number=2004>;privacy=off;screen=no;party=calling Contact: <sip:10.70.89.138:5073;transport=tls>;video;audio;+u.sip!devicename.ccm.cisco.com="CSFYANZAI";bfcp From: <sip:yanzai@collabdmz.lab>;tag=489402~d40ad9b5-e039-4814-9d0f-dbece52207f2-21292822 To: <sip:2104@dmz-cucm1.collabdmz.lab> Max-Forwards: 11 Allow: INVITE,ACK,BYE,CANCEL,INFO,OPTIONS,REFER,SUBSCRIBE,NOTIFY,UPDATE User-Agent: TANDBERG/4352 (X12.6.4-b2bua-1.0) Supported: replaces,timer Session-Expires: 1800;refresher=uac Min-SE: 500 P-Asserted-Identity: <sip:yanzai@collabdmz.lab> X-TAATag: 7b51bdc6-c64b-4cf5-9593-3c03193dfaf0 Send-Info: conference,x-cisco-conference Session-ID: 3fee64dd00105000a000acde48001122;remote=00000000000000000000000000000000 Alert-Info: <file://Bellcore-dr1/> Content-Length: 0
サインアウト: Device Token の削除
Jabber 側でユーザーがサインアウトを行うと Unified CM 側の Token が削除されるため、該当デバイスに対しては Push 通知が送信されなくなります。ここでのサインアウトは明示的に以下の画像の Sign Out をタップすることを意味します。
Jabber for iPhone
ユーザーがサインアウトをタップし、Unified CM に Token 削除のリクエストを送信
2021-08-24 13:56:22,272 INFO [0x0000000108a8f8c0] [i/mainframe/YLCSidebarCellFactory.m(244)] [UI.Action.User] [-[YLCSidebarCellFactory signOut]] - User tap sign out on sidebar 2021-08-24 13:56:22,300 INFO [0x000000016ed5b000] [nts/ecc/src/config/UDSRetriever.cpp(373)] [csf.ecc] [deleteDeviceToken] - deleteDeviceToken 2021-08-24 13:56:22,300 DEBUG [0x000000016ed5b000] [onents/ecc/src/config/UDSClient.cpp(409)] [csf.ecc] [deleteDeviceToken] - delete device token url=https://dmz-cucm1.collabdmz.lab:8443/cucm-uds/user/yanzai/device/4f4e7dd4-07b2-c145-6aac-4c8ddc382de9/devicetoken/01d84a2520d6560567e7c03e1b7e30d97969d9a8cda347096b829cd71f06ca4b
Unified CM: User Data Service (UDS)
Jabber から Token の削除リクエストを受け、DB から Token を削除
2021-08-24 13:56:20,852 DEBUG [http-nio-1026-exec-4] security.ThrottleFilter - Request: DELETE /user/yanzai/device/4f4e7dd4-07b2-c145-6aac-4c8ddc382de9/devicetoken/01d84a2520d6560567e7c03e1b7e30d97969d9a8cda347096b829cd71f06ca4b completed in: 13ms
Unified CM: Cisco CallManager
DB から Token が削除されたことが LineControl プロセスに通知される
12662197.000 |13:56:21.018 |SdlSig |CcmDbTableChangeNotify |wait |CcmDbChangeNotify(1,100,223,1) |CcmDbChangeNotify(1,100,223,1) |1,100,223,1.1393^*^* |[T:N-H:0,N:1,L:0,V:0,Z:0,D:0] 12662197.001 |13:56:21.018 |AppInfo |SMDMSharedData::findLocalDevice - Name=2104: Key=da01ccc5-a723-c4c4-0994-f03db7e2c3f9 isActvie=1 Pid=(1,85,11) found 12662198.000 |13:56:21.018 |SdlSig |DmDeviceTokenCNF |restart0 |LineControl(1,100,85,11) |DeviceManager(1,100,53,1) |1,100,223,1.1393^*^* |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] devPkid=4f4e7dd4-07b2-c145-6aac-4c8ddc382de9 endUserPkid=3db32849-55de-9d36-d2b6-2f252422f9a1 token= 12662199.000 |13:56:21.018 |SdlSig |CcmDbTableChangeNotify |wait |CcmDbChangeNotify(1,100,223,1) |CcmDbChangeNotify(1,100,223,1) |1,100,223,1.1394^*^* |[T:N-H:0,N:0,L:0,V:0,Z:0,D:0]
トラブルシューティングに有効なコマンド
以下ではトラブルシューティングに利用できるコマンドを紹介します。
Unified CM: Token の確認
以下のコマンドを利用することで DB での Device token の保持状況を確認することが出来ます。ユーザーがサインアウトを行った際にはテーブルから Device token が削除されます。また、サインイン、およびサインインした状態で Jabber を起動した場合は、起動の度に Device token が Unified CM へ送信されます。
run sql SELECT dev.name, token.*, DBINFO('utc_to_datetime', token.cdrtime) as last_update FROM device as dev INNER JOIN devicetokendynamic as token ON dev.pkid in (token.pkid, token.fkdevice) WHERE dev.name = '<Device Name>'
以下はサインアウト -> サインイン -> スワイプで終了 -> 再度起動を行った際の各段階の実際のコマンド実行結果となります。
2021-08-26 14:19:27 にサインアウトした後の DB
- 最後にサインアウトした際に Device token が削除されたことが分かる
- last_update カラムから、サインアウトした時刻に Device token が削除されたことが確認できる
admin:run sql SELECT dev.name, token.*, DBINFO('utc_to_datetime', token.cdrtime) as last_update FROM device as dev INNER JOIN devicetokendynamic as token ON dev.pkid in (token.pkid, token.fkdevice) WHERE dev.name = 'TCTYANZAI'
name pkid fkdevice fkenduser pushnotifytoken pushchanneltype key algorithm application payloadversion devicetoken iscallkitdisabled last_update
========= ==================================== ==================================== ==================================== =============== =============== ==== ========= =========== ============== =========== ================= ===================
TCTYANZAI 4f4e7dd4-07b2-c145-6aac-4c8ddc382de9 4f4e7dd4-07b2-c145-6aac-4c8ddc382de9 3db32849-55de-9d36-d2b6-2f252422f9a1 NULL NULL NULL NULL NULL NULL NULL f 2021-08-26 14:19:27
なお、fkdevice が ログから確認できる Device ID となります。
2021-08-31 18:45:25 にサインインした後の DB
- Device token が pushnotifytoken に登録されていることが確認できる
- last_update カラムからサインイン時に DB がアップデートされていることが確認できる
admin:run sql SELECT dev.name, token.*, DBINFO('utc_to_datetime', token.cdrtime) as last_update FROM device as dev INNER JOIN devicetokendynamic as token ON dev.pkid in (token.pkid, token.fkdevice) WHERE dev.name = 'TCTYANZAI'
name pkid fkdevice fkenduser pushnotifytoken pushchanneltype key algorithm application payloadversion devicetoken iscallkitdisabled last_update
========= ==================================== ==================================== ==================================== ================================================================ =============== =========================================== ========= =========== ============== =========== ================= ===================
TCTYANZAI 4f4e7dd4-07b2-c145-6aac-4c8ddc382de9 4f4e7dd4-07b2-c145-6aac-4c8ddc382de9 3db32849-55de-9d36-d2b6-2f252422f9a1 01d84a2520d6560567e7c03e1b7e30d97969d9a8cda347096b829cd71f06ca4b APNS b-a8LYvi6owHWhrqBDOEUXPoocK-jzSG2NmGA_NOZbA A256GCM jabber V2 NULL f 2021-08-31 18:45:25
2021-08-31 18:46:15 にアプリをスワイプで終了し再度起動した際の DB
- Device token は同一だが、last_update カラムから起動時にアップデートされていることが確認できる
admin:run sql SELECT dev.name, token.*, DBINFO('utc_to_datetime', token.cdrtime) as last_update FROM device as dev INNER JOIN devicetokendynamic as token ON dev.pkid in (token.pkid, token.fkdevice) WHERE dev.name = 'TCTYANZAI'
name pkid fkdevice fkenduser pushnotifytoken pushchanneltype key algorithm application payloadversion devicetoken iscallkitdisabled last_update
========= ==================================== ==================================== ==================================== ================================================================ =============== =========================================== ========= =========== ============== =========== ================= ===================
TCTYANZAI 4f4e7dd4-07b2-c145-6aac-4c8ddc382de9 4f4e7dd4-07b2-c145-6aac-4c8ddc382de9 3db32849-55de-9d36-d2b6-2f252422f9a1 01d84a2520d6560567e7c03e1b7e30d97969d9a8cda347096b829cd71f06ca4b APNS b-a8LYvi6owHWhrqBDOEUXPoocK-jzSG2NmGA_NOZbA A256GCM jabber V2 NULL f 2021-08-31 18:46:15
Unified CM: Cisco Cloud への疎通性の確認
Unified CM が Cisco Cloud に対して疎通性がない場合には Push 通知が失敗します。この切り分けには Unified CM と同セグメントにあるプラットフォームから以下のコマンドを利用することで疎通性の有無を確認できます。
curl -v https://push.webexconnect.com/ping注：Unified CM では curl コマンドが利用できません。
Cisco Cloud の正常性の確認は以下のドキュメントも併せてご確認ください。
発生する問題例とトラブルシューティング方法
プッシュが遅延して届く
Callmanager, CPNS, Jabber for iPhone ログを順番に確認して、どの経路にてレスポンスが遅れているか確認してください。特に CPNS がリクエストを送信してからレスポンスを受ける間で遅延している場合は Firewall やプロキシなども含めて Cisco Collaboration Cloud までの経路で遅延が発生していないか確認する必要があります。 Cisco Collaboration Cloud 側の調査を希望される場合は後述のログを収集して TAC までケースオープンしてください。
Jabber がバックグラウンドの際に着信が出来ない
Callmanager, CPNS, Jabber for iPhone ログを順番に確認して、適切に Push リクエストが各段階で送信されているか、エラーが返ってきていないかを確認してください。すべての端末で着信が必ずできない場合は Unified CM で Cloud Onboarding が適切に設定されているかも確認してください。
また、WLAN 環境でネットワーク側の切り分けのためにパケットキャプチャを行う場合は以下のドキュメントも併せてご確認ください。
・iPhone / iPad でパケットキャプチャを行う方法
着信を受話しても無音となり、該当コールが着信履歴に残らない
SIP INVITE に先行して Push が着信した時点で Jabber for iPhone は鳴動を始めるため、SIP INVITE が届く前に受話をした場合本事象が発生することがあります。通常は SIP INVITE と Push の着信はほぼ同時に到着するため問題にはなりませんが、Push が何らかの理由で遅延している場合などにこの問題が併発する可能性があります。
・ Jabber for iPhone で Push 通知を受信し INVITE を受信しない際に着信音が鳴り続ける
Cisco TAC にケースを上げる際に必要な情報
Push 通知に関して問題が発生した場合には以下のドキュメントを参考に指定のログレベルでログを収集して下さい。
参考情報
- Jabber for iPhone の着信動作について （iOS13以降の新方式）
- Jabber for iPhone の APNs のトラブルシューティングに役立つログ
- APNs: Cisco Collaboration Cloud の正常性の確認方法
- Field Notice: FN - 70555 - Legacy VoIP Mode and iOS 13 Apple Push Notification Service Changes That Affect Cisco Jabber, Cisco Webex Teams, Cisco Unified Communications Manager and IM & Presence Service, and Cisco Expressway - Software Upgrade Recomm...
- Jabber for iPhone を WLAN 環境で使用する際の NAT タイマー 値の設定について
- Apple.com: Apple 製のデバイスで Apple プッシュ通知が届かない場合
- iPhone / iPad でパケットキャプチャを行う方法
- Tracking ID による Jabber for iPhone コールの追跡調査について
- Jabber for iPhone で Push 通知を受信し INVITE を受信しない際に着信音が鳴り続ける
検索バーにキーワード、フレーズ、または質問を入力し、お探しのものを見つけましょう
シスコ コミュニティをいち早く使いこなしていただけるよう役立つリンクをまとめました。みなさんのジャーニーがより良いものとなるようお手伝いします
