Incoming call and registration

Process

Caller (발신측)가 전화를 걸어 Callee (수신측)에게 연결이 되는 과정 까지를 밑에 Log를 통해 살펴 볼 수 있다. 

---

Sample

• 다양한 Call Flow를 접할 수 있어야 나중에 Signaling Error 발생시에 어느 위치에서 발생 했는지 정확한 Reporting이 가능하다. 기본적인 호 접속의 Flow 이며 Signaling 기획에 따라 다소 다른 규격이 있을 수도 있지만 대부분의 내용이 밑에 Log에 포함 되어 있으므로 이런 Log를 통해 원인 및 isssue를 찾아 내는 것이 중요하다.
• 해당 내용은 국내 서비스 중인 mVoIP 서비스 중에 하나로 Debug mode상태라 Log 확인이 가능하다. 만일 테스트를 위한 검증이라면 개발자에게 Debug Level을 내려서 이런 로그들이 출력 될 수 있게끔 요청하는것도 편안한 검증의 방법이다.
• 가급적 해당 소스 중 일부는 ********으로 표시함.
  
  
  =====================================   Log Print  =========================================
   
  최초 단말 실행시에 Build version 및 날짜 Log확인
  V/UNDIFINED(3870): ==================================================
  V/UNDIFINED(3870):  BuildVersion:   ####-AA-010002
  V/UNDIFINED(3870):  BuildDate:      Jul 12 2013 14:17:48
  V/UNDIFINED(3870): ==================================================
  버전 확인 이후 /system/lib/egl/ 에서 so파일들을 Load 한다.
   
  KMVOIP [doRegistration] Signaling Server ipAddress = 159.253.157.106 | at kr.co.********.library.voip.********EngineDriver.do********Registration(********EngineDriver.java:2481)
  à Log 내용으로 Signaling server IP 확인
   
  KMVOIP [doRegistration] Signaling Server portNumber = 8441 | at kr.co********.library.voip********EngineDriver.do********Registration(********EngineDriver.java:2482)
  à Log 내용으로 Signaling server IP 확인 (server port는 8440~8447중에 Random하게 열린다)
   
  KMVOIP [doRegistration] mserverIp = 1.234.25.201 | at kr.co.tictocplus.library.voip.SoraEngineDriver.doSORARegistration(SoraEngineDriver.java:2484)
  à Log 내용으로 Mserver IP 확인
   
  KMVOIP [doRegistration] mserverPort = 23018 | at kr.co.********.library.voip.********EngineDriver.do********Registration(********EngineDriver.java:2485)
  à Log 내용으로 Mserver port 확인
   
  UNDIFINED       Provision 1.234.68.220:7000 1.234.25.201:23018 [821021466570]à Provisioning server 접속 확인
   
  단말을 인식하는 MDN값을 현재 USN값으로 변경함에 따라서 server쪽으로 trace를 시도할때에는 USN 값을 알아야 한다. 보통 UNDIFINED tag 가 되어 있는 부분에서 from 이나 to 쪽의 call USN을 Find 하면 확인이 가능함.
  UNDIFINED       To         : 900000000000100274
   
  단말이 인증을 시도하는 메시지를 Server 측으로 전송하면 server로부터 401응답을 받게 된다. UNDIFINED tag부분에서 Recv Information의 Response부분에서 확인이 가능하다.
  *server로부터 확인한 메시지
  ----------- Recv Information ----------
   Response   : 0x0191 (401)
   ViaBranch  : 0x2c9 (713)
   StartLine  : 0x8191 (33169)
   Reason     : 0x0000 (0)
   CallID     : 0x2c9 (713)
   From       : 900000000000100274
   FromTag    : 0x2c9 (713)
   Retry Cnt  : 0
  ---------------------------------------
  *server로부터 recv를 확인했다고 보내는 메시지
  ------- Send Signal Information -------
   StartLine  : 0x400c (16396)
   Response   : 0x0000 (0)
   ViaBranch  : 0x2cb (715)
   Reason     : 0x0000 (0)
   CallID     : 0x2cb (715)
   From       : 900000000000100274
   FromTag    : 0x2cb (715)
   To         : 900000000000100274
   ToTag      : 0x0 (0)
  ---------------------------------------
   
  인증에 성공한 뒤 (최초1회) dovoicecall을 이용해 call을 발신 시도 하는 Log를 뿌려준다.
  KMVOIP Call doS********VoiceCall | at kr.co********.library.voip.SoraEngineDriver.onS********RegistrationResult(********EngineDriver.java:2592)
  KMVOIP =========== doVoiceCall ============= | at kr.co.********.library.voip********aEngineDriver.do********AVoiceCall(********EngineDriver.java:922)
  KMVOIP getPeerDisplayName() : 갤럭시s3 고유번호ㅋ | at kr.co.********s.library.voip.********EngineDriver.do********AVoiceCall(********EngineDriver.java:940)
  kr.co********   KMVOIP fromNumber : 900000000000100274 | at kr.co.********s.library.voip.********EngineDriver.do********VoiceCall(S********EngineDriver.java:941)
  kr.co.********   KMVOIP toNumber : 821021466570 | at kr.co.********s.library.voip.********EngineDriver.do********VoiceCall(********aEngineDriver.java:942)
   
  * Auth 인증 case
  *앞서 설명한 401인증은 최초 App에 진입하여 연결하는 과정에서 1회만 인증을 시행 하고 이후에 Relay server에 진입할 때는 401인증을 계속 진행 하지 않고 next nonce를 통한 인증을 시도하도록 구현되어 있다.
  UNDIFINED       UAC [RELAY] 222.239.254.199
  UNDIFINED       For NAT. Transaction current : 4 : next : 5
  UNDIFINED       Digest[-1662866650]=0x4014179C
  UNDIFINED       Digest[-984824826]=0x587DB7A3
  UNDIFINED       Digest[-687129467]=0x587DB7A3
  UNDIFINED       Digest[-379218203]=0x587DB7A3
  UNDIFINED       Digest[-485930902]=0x587DB7A3
  ********Application      [T:587][logSignalingEvent][L:32] mEvent : EVENT_SIGNALING_SUCCESS
  ********Application                       mState : STATE_SIGNALING_INVITE_PRE_OFFERING
  ********Application       [T:587][logNatEvent][L:164] mEvent : EVENT_NAT_SUCCESS
  ********Application                        mState : NAT_STATE_TRY_REQUEST
  KMVOIP_HANDLER         mEvent : EVENT_NAT_SUCCESS
  KMVOIP_HANDLER                         mState : NAT_STATE_TRY_REQUEST | at kr.co.********.s********.util.LogUtil.logNatEvent(LogUtil.java:165)
   
  àTransaction current를 통해 request 순서를 확인 할 수 있고 해당 request가 10회 실패하면 Call은 미 발신 처리로 돌아가게 된다.
  
  통화 중 120sec 마다 호 연결 유지를 위해서 120초 마다 server쪽으로 refresh request를 보내고 응답을 받으면 Signaling을 유지 하게 된다. 최초 120sec로 연결이 되고 이후에 90sec로 연결 주기가 줄어들면서 request 요정이 있다. 만일 요청 값이 server측으로 정상 전송이 이루어 지지 못할 경우 하기의 로그 처럼 Call이 종료됨
  V/UNDIFINED(29264): [CSignalingUserAgent::OnMessage:583] ID : 1008
  V/UNDIFINED(29264): ==================================================
  E/UNDIFINED(29264):  Packet Alive Timer expired
  V/UNDIFINED(29264): ==================================================
  V/UNDIFINED(29264): [CSignalingUserAgent::HandleEvent] message = 0xA000200(167772672), wParam = 27
  V/UNDIFINED(29264): [CSignalingUserAgent::NatHandleEvent] message = 0xA000200(167772672), wParam = 27
  V/UNDIFINED(29264): [CSignalingUserAgent::DelegateEvent] message = 0xA000200(167772672), wParam = 27
  V/UNDIFINED(29264): [CSignalingUserAgent::DelegateEvent] OK!!!
  V/UNDIFINED(29264): [CSignalingUserAgent::OnMessage:583] ID : 1016
   
  해당 현상이 있기 전 RETRY REFRESH REQUEST를 요청 하지만 일반적으로 요청한 값에 대해서 서버측으로 가는 응답이 없게 되면 10회를 요청하고 이후에 재전송 Life time 때에 호가 종료 되게 된다
   
  정상적으로 전송되는 경우에는 하기와 같이 RETRY REFRESH REQUEST를 보내고 SignalPacket 값으로 data를 보낸 의미로 length와 first byte (header로 생각됨) Log를 보여준다. (자세한 Log는 tcpdump를 통해 확인 가능)
   
  UNDIFINED       [CSignalingUserAgent::OnMessage:583] ID : 1003
  UNDIFINED       RETRY REFRESH REQUEST  [10]
  UNDIFINED       UAC [RELAY] 222.239.254.200
  UNDIFINED       [CMmfNatRefresh::Request_] refresh dwLifetime = 120, sProxy=222.239.254.200, wPort=7849
  UNDIFINED       [CSignalingUserAgent::onSignalPacketRead:664] Got signaling packet during call
  UNDIFINED       [CSignalingUserAgent::onSignalPacketRead:665] packet len:20996 firstbyte:77
  
  * 수신case
  KMVOIP Provisioning 이 이미 되었으므로 Registration 을 진행한다. | at kr.co.********s.library.voip.********EngineDriver.startIncoming(********EngineDriver.java:2446)
  프로비져닝이 이미 이루어져 있는 경우(최초 인증) Registration을 하고 바로 tcp socket을 열어준다
   
  외부 relay server를 통해 address와 signaling 정보들을 보낸다.
  UNDIFINED       a callee must set caller's relay address : 222.239.254.199
  UNDIFINED      
  UNDIFINED       ------- Send Signal Information -------
  UNDIFINED       StartLine  : 0x8064 (32868)
  UNDIFINED       Response   : 0x0064 (100)
  UNDIFINED       ViaBranch  : 0x1 (1)
  UNDIFINED       Reason     : 0x0000 (0)
  UNDIFINED       CallID     : 0x7c5000 (8146944)
  UNDIFINED       From       : 820000000000129626
  UNDIFINED       FromTag    : 0x7c5000 (8146944)
  UNDIFINED       To         : 821021466570
  UNDIFINED       ToTag      : 0x0 (0)
  UNDIFINED       ---------------------------------------
   
  마찬가지로 Next nonce인증을 받았다면 다음은 자동으로 Allocation request를 통해 인증 관리를 다음과 같이 진행 해 주고 정상동작으로 되면 NAT 연결을 success 해준다.
  UNDIFINED       For NAT. Transaction current : 4 : next : 5
   
  UNDIFINED       ------- NatTransport Information ------
  UNDIFINED       Recv Packet      : 64
  UNDIFINED       Remote 222.239.254.199:7849
  UNDIFINED       ---------------------------------------
   
  이후 180ringing이 울리게 되고 해당 180 수신을 하였음을 알리는 signaling msg를 전송한다.
  UNDIFINED       ------- Send Signal Information -------
  UNDIFINED       StartLine  : 0x80b4 (32948)
  UNDIFINED       Response   : 0x00b4 (180)
  UNDIFINED       ViaBranch  : 0x1 (1)
  UNDIFINED       Reason     : 0x0000 (0)
  UNDIFINED       CallID     : 0x7c5000 (8146944)
  UNDIFINED       From       : 820000000000129626
  UNDIFINED       FromTag    : 0x7c5000 (8146944)
  UNDIFINED       To         : 821021466570
  UNDIFINED       ToTag      : 0x175 (373)
  UNDIFINED       ---------------------------------------
  
  통화를 받기 위한 모든 연결이 정상적으로 완료 되었다면 NAT 정보를 보여 주고 소켓바인딩을 열어 주고 해당 정보를 알려 준다. 이후에 연결된 candidate Type을 보여준 뒤 Msg의 parameter 값을 확인 후 정상적인 통화에 진입하고 (ready 상태) ICE를 열어서 통화를 위한 session을 열어 준다   (통화를 하기 위해 Signaling Server를 열고 1.234.68.218:8440 으로 접속을 시도한다)
  Relay server를 여는 경우에는 1.234.68.XXX 서버를 통해 연결이 이루어 진다.
  UNDIFINED(3870): ------- NatTransport Information ------
  UNDIFINED(3870):  Recv Packet      : 24
  UNDIFINED(3870):  Remote 222.239.254.200:58152
  UNDIFINED(3870): ---------------------------------------
  UNDIFINED(3870): ------------ Binding Info -------------
  UNDIFINED(3870):  Method: 0x1 (1)
  UNDIFINED(3870):  Class : 0x2 (2)
  UNDIFINED(3870):  TID   : 201326848
  UNDIFINED(3870): ---------------------------------------
  UNDIFINED(3870):>>> virtual void CMmfNatIceProcedure::OnReceived(int) 271 Responsed IP:0xdeeffec8 port:58152
  UNDIFINED(3870):>>> candidateType : 8
  UNDIFINED(3870): [CSignalingUserAgent::HandleEvent] message = 0xA000200(167772672), wParam = 20
  UNDIFINED(3870): [CSignalingUserAgent::NatHandleEvent] message = 0xA000200(167772672), wParam = 20
  UNDIFINED(3870): ==================================================
  UNDIFINED(3870):  ICE COMPLETED [8]
  UNDIFINED(3870): ==================================================
  UNDIFINED(3870): [CSignalingUserAgent::DelegateEvent] message = 0xA000200(167772672), wParam = 20
  UNDIFINED(3870): [CSignalingUserAgent::DelegateEvent] OK!!!
   
  통화를 받게 된다면 받았다는 signaling msg를 보내고 그에 대한 200 ok를 받고 Media straming 열어 통화를 한다.