2014-07-21 11:30:41.004125 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51914 size=144. Stream 20:CLEAR:START 2014-07-21 11:30:41.084123 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.084123 [DEBUG] sofia.c:5779 Channel sofia/internal/1001@135.252.186.206 entering state [ready][200] 2014-07-21 11:30:41.084123 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/sip:1002@135.240.10.210 [BREAK] 2014-07-21 11:30:41.084123 [DEBUG] switch_core_session.c:933 Send signal sofia/internal/1001@135.252.186.206 [BREAK] 2014-07-21 11:30:41.104164 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.104164 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51915 size=144. Stream 20:CLEAR:START 2014-07-21 11:30:41.124160 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.144150 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.164130 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.184162 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.204131 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.224160 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.244185 [DEBUG] switch_rtp.c:3727 Correct ip/port confirmed. 2014-07-21 11:30:41.244185 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.304170 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51916 size=144. Stream 20:CLEAR:START 2014-07-21 11:30:41.324181 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Received packet with ssrc=2087558422 seq=384/384 size=136. Stream20:CLEAR:START. 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Processing HELLO from LINPHONE-ZRTPCPP V=1.10, P=0, M=0. 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp engine]: ac=2 cc=1 sc=1 kc=3 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp engine]: S256AES1HS32HS80DH3kDH2kMultB32 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Received HELLO had the same protocol V. 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp utils]: _zrtp_choose_best_comp() for PKT. local=DH3k remote=DH3k, choosen=DH3k 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Received HELLO Accepted 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp cache]: ache_get(): zid1=383766636261636564366363, zis2=8ec558eeca49b5a0099f6626 MiTM=NO 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp cache]: ache_get(): zid1=383766636261636564366363, zis2=8ec558eeca49b5a0099f6626 MiTM=NO 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp cache]: ache_get(): zid1=383766636261636564366363, zis2=8ec558eeca49b5a0099f6626 MiTM=YES 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Restoring Secrets: lZID=383766636261636564366363 rZID=8ec558eeca49b5a0099f6626. V=1 sID=20 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp utils]: RS1 <29ddc32434d93d873d9eed62e888ffc9488174526e8b9f066d596251ddfd50d3> 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp utils]: RS2 <8460973f17cebe3964d279f5a69a4315f67b53fd0cfd04cf08a1eb94b1ea5f3f> 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp utils]: PBX <00104da9b6175251cf4d98ebde3dbc3d09f32603c32862399f1707af82461ebf> 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51917 size=28. Stream 20:CLEAR:START 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp]: Stream ID=20 CLEAR switching ---> . 2014-07-21 11:30:41.344161 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.504180 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51918 size=144. Stream 20:CLEAR:W4HACK 2014-07-21 11:30:41.524160 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.524160 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.524160 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Received packet with ssrc=2087558422 seq=385/385 size=136. Stream20:CLEAR:W4HACK. 2014-07-21 11:30:41.524160 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51919 size=28. Stream 20:CLEAR:W4HACK 2014-07-21 11:30:41.584126 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Received packet with ssrc=2087558422 seq=386/386 size=28. Stream20:CLEAR:W4HACK. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp]: Stream ID=20 CLEAR switching ---> . 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Initiating Secure iteration... ID=20. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Got mode=DH. Check approval of starting. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Mode=DH Cccepted. Starting ZRTP Initiator Protocol. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: ENTER STATE INITIATING SECURE for ID=20 mode=DH state=SINITSEC. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: Initiator selected following options: 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: Hash: S256 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: Cipher: AES1 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: ATL: HS32 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: VAD scheme: B32 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Init INITIATOR's Protocol ID=20 mode=DH... 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp dh]: DH TEST: DH3k zrtp_dh_initialize() START. now=1405913441604ms. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp dh]: DH TEST: zrtp_dh_initialize() for DH3k was executed ts=1405913441612ms d=8ms. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS id=06355485e0752a7b. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS peer_id=3a61fe223b0aca32. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS id=1b83110295092671. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS peer_id=928656db608ba9b0. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS id=d83ad268ee780d56. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS peer_id=89dadcf8e1852bd2. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS id=5a3950c8b31e114c. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS peer_id=f39f52b53abbb422. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp]: Stream ID=20 DH switching ---> . 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: Start Sending COMMIT ID=20 mode=DH state=INITSEC: 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: Hash: S256 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: Cipher: AES1 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: ATL: HS32 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: PK scheme: DH3k 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: VAD scheme: B32 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp initiat]: hv: 5135f866335704c0a695e2923871c2ab7935069efe21ce61a30d740aeae5a678 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51920 size=132. Stream 20:DH:INITSEC 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Received packet with ssrc=2087558422 seq=387/387 size=132. Stream20:DH:INITSEC. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp respond]: Preparse incoming COMMIT. Remote peer wants DH3k:2 mode lic=1 peer M=0. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp respond]: Both sides are in INITIATINGSECURE State - BREACK the TIE. ID=20 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp respond]: Chosen Responder State-Machine. Change Mode to DH, pkt to DH3k 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp respond]: ENTER STATE PENDING SECURE for ID=20 mode=DH state=INITSEC. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp respond]: Remote COMMIT specified following options: 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp respond]: Hash: S256 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp respond]: Cipher: AES1 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp respond]: ATL: HS32 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp respond]: PK scheme: DH3k 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp respond]: VAD scheme: B32 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp]: Stream ID=20 DH switching ---> . 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Init RESPONDER's Protocol ID=20 mode=DH... 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS id=3a61fe223b0aca32. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS peer_id=06355485e0752a7b. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS id=928656db608ba9b0. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS peer_id=1b83110295092671. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS id=89dadcf8e1852bd2. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS peer_id=d83ad268ee780d56. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS id=f39f52b53abbb422. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Attach RS peer_id=5a3950c8b31e114c. 2014-07-21 11:30:41.604177 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51921 size=484. Stream 20:DH:PENDSEC 2014-07-21 11:30:41.624218 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.624218 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.644164 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.644164 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.664162 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.664162 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.684193 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.684193 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.704160 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.704160 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Received packet with ssrc=2087558422 seq=388/388 size=484. Stream20:DH:PENDSEC. 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: --------------------------------------------------- 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: SWITCHING TO SRTP. ID=2031578122 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: I Responder 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: DERIVE S0 from DH exchange and RS secrets... 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: my rs1ID:3a61fe223b0aca32 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: his rs1ID:06355485e0752a7b 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: his rs1ID comp:06355485e0752a7b 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: my rs2ID:928656db608ba9b0 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: his rs2ID:1b83110295092671 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: his rs2ID comp:1b83110295092671 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: my pbxsID:f39f52b53abbb422 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: his pbxsID:2852e89216ba9853 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: his pbxsID comp:5a3950c8b31e114c 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: DH comp_length=384 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [ zrtp dh]: DH TEST: DH3k zrtp_dh_compute() START. now=1405913441724ms. 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [ zrtp dh]: DH TEST: zrtp_dh_compute() for DH3k was executed ts=1405913441734ms d=10ms. 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Use S1 in calculations. 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: HMAC TRACE. COMPUTE. 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: cipher text:8fc3bce1865fa67016f14165f51d293aa4c440972e8aba9c0bff1abb5310632139ec8cfe015cbf3e. size=40 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: key:fa2d39ec2f7fdeb26e4f5e512dafb147849c49964b5b8e2921ea33c2646840da. 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: comp hmac:9e1f2be1d53daf717b9535da3828d1ccb8d2c46878fd4941e4b15a19998e15df. 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: hmac:9e1f2be1d53daf71. 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [ zrtp]: Stream ID=20 DH switching ---> . 2014-07-21 11:30:41.724156 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51922 size=92. Stream 20:DH:W4CONF2 2014-07-21 11:30:41.744277 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.744277 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.764219 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.764219 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.784149 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.784149 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.804158 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.804158 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.824196 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.824196 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.844172 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.844172 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.864162 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.864162 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Add 172 bytes of entropy to the RNG pool. 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Received packet with ssrc=2087558422 seq=389/389 size=92. Stream20:DH:W4CONF2. 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [zrtp protoco]: INFO: Other side Confirm V=0 - set verified to 0! ID=20 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp cache]: Storing ZRTP cache to ... 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51923 size=28. Stream 20:DH:W4CONF2 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Enter state SECURE (DH). 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [zrtp protoco]: This is the very first stream in sID GENERATING SAS value. 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [zrtp protoco]: SAS computed: <>. 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Check expiration interval: last_use=1405501868 ttl=4294967295 new_ttl=4294967295 exp=1405501867 now=1405913441 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [zrtp protoco]: Flags C=26 M=6 W=0 ID=20 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp]: Stream ID=20 DH switching ---> . 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp cache]: Storing ZRTP cache to ... 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [zrtp protoco]: INFO! The user requires new un-enrolment - the nedpint may clear the cache or perform other action. ID=20 2014-07-21 11:30:41.884187 [DEBUG] switch_core_sqldb.c:2357 Secure Type: zrtp:qpxh: 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:898 User unenrolled! 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [zrtp protoco]: INFO! The user requires new enrolment - generate new MiTM secret. ID=20 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: MARKING this call as REGISTRATION ID=20 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp cache]: cache_put() zid1=383766636261636564366363, zis2=8ec558eeca49b5a0099f6626 MiTM=YES 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp cache]: cache_put() Just update existing value. 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp cache]: Storing ZRTP cache to ... 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp cache]: 1 out of 2 MiTM cache entries have been flushed successfully. 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: Makring this call as REGISTRATION - DONE 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:891 New user enrolled! 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp cache]: cache_put() zid1=383766636261636564366363, zis2=8ec558eeca49b5a0099f6626 MiTM=NO 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp cache]: cache_put() Just update existing value. 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp cache]: Storing ZRTP cache to ... 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp cache]: 1 out of 2 regular cache entries have been flushed successfully. 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [zrtp protoco]: New secret was generated: 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [zrtp protoco]: RS1 value:<5b29d91557a8c0c7f85671c8c3ab834e5e6836ab3d36be2d4a8ca755edbf8c7a> 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [zrtp protoco]: TTL=4294967295, flags C=26 M=26 W=0 V=1 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp cache]: Storing ZRTP cache to ... 2014-07-21 11:30:41.884187 [DEBUG] switch_rtp.c:927 [ zrtp cache]: 1 out of 2 regular cache entries have been flushed successfully. 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: RESOLVE MITM CALL s1=20, s2=19... 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: Both streams are enrolled - choose one with bigger ZID. 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: After Resolving: S1 is NON-ENROLLED and S2 is ENROLLED. 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: MITM SAS scheme=B32 was choosen. 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: UPDATE REMOTE SAS OPTIONS mode. ID=19 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: transf_sas=735fc2b92a833aa2f17a4c0bbb1bd6fd7eaffcea299a6f2dcfc57a37dfcb12fe scheme=1. 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [ zrtp]: Stream ID=19 DH switching ---> . 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1272298498 seq=47653 size=92. Stream 19:DH:SASRELAY 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: UPDATE REMOTE SAS OPTIONS mode. ID=20 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: transf_sas=NULL scheme=1. 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [ zrtp]: Stream ID=20 DH switching ---> . 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51924 size=92. Stream 20:DH:SASRELAY 2014-07-21 11:30:41.904140 [DEBUG] switch_rtp.c:927 [zrtp protoco]: ERROR! Decrypt failed. ID=20:DH s=SRTP authentication failure (RTP size=172 ssrc=2087558422 seq=13/13 pt=0) 2014-07-21 11:30:41.924173 [DEBUG] switch_rtp.c:927 [zrtp protoco]: ERROR! Decrypt failed. ID=20:DH s=SRTP authentication failure (RTP size=172 ssrc=2087558422 seq=14/14 pt=0) 2014-07-21 11:30:41.944189 [DEBUG] switch_rtp.c:927 [zrtp protoco]: ERROR! Decrypt failed. ID=20:DH s=SRTP authentication failure (RTP size=172 ssrc=2087558422 seq=15/15 pt=0) 2014-07-21 11:30:41.964166 [DEBUG] switch_rtp.c:927 [zrtp protoco]: ERROR! Decrypt failed. ID=20:DH s=SRTP authentication failure (RTP size=172 ssrc=2087558422 seq=16/16 pt=0) 2014-07-21 11:30:41.984125 [DEBUG] switch_rtp.c:927 [zrtp protoco]: ERROR! Decrypt failed. ID=20:DH s=SRTP authentication failure (RTP size=172 ssrc=2087558422 seq=17/17 pt=0) 2014-07-21 11:30:42.004162 [DEBUG] switch_rtp.c:927 [zrtp protoco]: ERROR! Decrypt failed. ID=20:DH s=SRTP authentication failure (RTP size=172 ssrc=2087558422 seq=18/18 pt=0) 2014-07-21 11:30:42.024187 [DEBUG] switch_rtp.c:927 [zrtp protoco]: ERROR! Decrypt failed. ID=20:DH s=SRTP authentication failure (RTP size=172 ssrc=2087558422 seq=19/19 pt=0) 2014-07-21 11:30:42.044156 [DEBUG] switch_rtp.c:927 [zrtp protoco]: ERROR! Decrypt failed. ID=20:DH s=SRTP authentication failure (RTP size=172 ssrc=2087558422 seq=20/20 pt=0) 2014-07-21 11:30:42.064183 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51925 size=92. Stream 20:DH:SASRELAY 2014-07-21 11:30:42.064183 [DEBUG] switch_rtp.c:927 [zrtp protoco]: ERROR! Decrypt failed. ID=20:DH s=SRTP authentication failure (RTP size=172 ssrc=2087558422 seq=21/21 pt=0) 2014-07-21 11:30:42.084168 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Received packet with ssrc=2087558422 seq=390/390 size=92. Stream20:DH:SASRELAY. 2014-07-21 11:30:42.084168 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1272298498 seq=47654 size=92. Stream 19:DH:SASRELAY 2014-07-21 11:30:42.364165 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51926 size=92. Stream 20:DH:SASRELAY 2014-07-21 11:30:42.384157 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1272298498 seq=47655 size=92. Stream 19:DH:SASRELAY 2014-07-21 11:30:42.964122 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51927 size=92. Stream 20:DH:SASRELAY 2014-07-21 11:30:42.984182 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1272298498 seq=47656 size=92. Stream 19:DH:SASRELAY 2014-07-21 11:30:44.164180 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51928 size=92. Stream 20:DH:SASRELAY 2014-07-21 11:30:44.184160 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1272298498 seq=47657 size=92. Stream 19:DH:SASRELAY 2014-07-21 11:30:45.364179 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51929 size=92. Stream 20:DH:SASRELAY 2014-07-21 11:30:45.384161 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1272298498 seq=47658 size=92. Stream 19:DH:SASRELAY 2014-07-21 11:30:46.564180 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51930 size=92. Stream 20:DH:SASRELAY 2014-07-21 11:30:46.584185 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1272298498 seq=47659 size=92. Stream 19:DH:SASRELAY 2014-07-21 11:30:47.784187 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51931 size=92. Stream 20:DH:SASRELAY 2014-07-21 11:30:47.804181 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1272298498 seq=47660 size=92. Stream 19:DH:SASRELAY 2014-07-21 11:30:48.984178 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51932 size=92. Stream 20:DH:SASRELAY 2014-07-21 11:30:49.004180 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1272298498 seq=47661 size=92. Stream 19:DH:SASRELAY 2014-07-21 11:30:50.184175 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1338834216 seq=51933 size=92. Stream 20:DH:SASRELAY 2014-07-21 11:30:50.204182 [DEBUG] switch_rtp.c:927 [ zrtp utils]: Send ssrc=1272298498 seq=47662 size=92. Stream 19:DH:SASRELAY 2014-07-21 11:30:51.384177 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: WARNING! SASRELAY Max retransmissions count reached. ID=20 2014-07-21 11:30:51.384177 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Enter InitiatingError State with ERROR:, notification Disabled. ID=20 2014-07-21 11:30:51.384177 [DEBUG] switch_rtp.c:927 [ zrtp]: Stream ID=20 DH switching ---> . 2014-07-21 11:30:51.404175 [DEBUG] switch_rtp.c:927 [ zrtp mitm]: WARNING! SASRELAY Max retransmissions count reached. ID=19 2014-07-21 11:30:51.404175 [DEBUG] switch_rtp.c:927 [ zrtp engine]: Enter InitiatingError State with ERROR:, notification Disabled. ID=19 2014-07-21 11:30:51.404175 [DEBUG] switch_rtp.c:927 [ zrtp]: Stream ID=19 DH switching ---> . 2014-07-21 11:31:01.824179 [DEBUG] switch_core_session.c:1016 Send signal sofia/internal/sip:1002@135.240.10.210 [BREAK] 2014-07-21 11:31:01.844183 [NOTICE] sofia.c:737 Hangup sofia/internal/sip:1002@135.240.10.210 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2014-07-21 11:31:01.844183 [DEBUG] switch_channel.c:3183 Send signal sofia/internal/sip:1002@135.240.10.210 [KILL] 2014-07-21 11:31:01.844183 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/sip:1002@135.240.10.210 [BREAK] 2014-07-21 11:31:01.844183 [DEBUG] switch_ivr_bridge.c:633 BRIDGE THREAD DONE [sofia/internal/sip:1002@135.240.10.210] 2014-07-21 11:31:01.844183 [DEBUG] switch_ivr_bridge.c:658 Send signal sofia/internal/1001@135.252.186.206 [BREAK] 2014-07-21 11:31:01.844183 [DEBUG] switch_core_state_machine.c:481 (sofia/internal/sip:1002@135.240.10.210) State EXCHANGE_MEDIA going to sleep 2014-07-21 11:31:01.844183 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1002@135.240.10.210) Running State Change CS_HANGUP 2014-07-21 11:31:01.844183 [DEBUG] switch_core_state_machine.c:679 (sofia/internal/sip:1002@135.240.10.210) State HANGUP 2014-07-21 11:31:01.844183 [DEBUG] mod_sofia.c:506 Channel sofia/internal/sip:1002@135.240.10.210 hanging up, cause: NORMAL_CLEARING 2014-07-21 11:31:01.844183 [DEBUG] switch_core_state_machine.c:48 sofia/internal/sip:1002@135.240.10.210 Standard HANGUP, cause: NORMAL_CLEARING 2014-07-21 11:31:01.844183 [DEBUG] switch_core_state_machine.c:679 (sofia/internal/sip:1002@135.240.10.210) State HANGUP going to sleep 2014-07-21 11:31:01.844183 [DEBUG] switch_core_state_machine.c:690 (sofia/internal/sip:1002@135.240.10.210) Callstate Change ACTIVE -> HANGUP 2014-07-21 11:31:01.844183 [DEBUG] switch_core_state_machine.c:447 (sofia/internal/sip:1002@135.240.10.210) State Change CS_HANGUP -> CS_REPORTING 2014-07-21 11:31:01.844183 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/sip:1002@135.240.10.210 [BREAK] 2014-07-21 11:31:01.844183 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/sip:1002@135.240.10.210) Running State Change CS_REPORTING 2014-07-21 11:31:01.844183 [DEBUG] switch_core_state_machine.c:762 (sofia/internal/sip:1002@135.240.10.210) State REPORTING 2014-07-21 11:31:01.844183 [DEBUG] switch_core_state_machine.c:92 sofia/internal/sip:1002@135.240.10.210 Standard REPORTING, cause: NORMAL_CLEARING 2014-07-21 11:31:01.844183 [DEBUG] switch_core_state_machine.c:762 (sofia/internal/sip:1002@135.240.10.210) State REPORTING going to sleep 2014-07-21 11:31:01.844183 [DEBUG] switch_core_state_machine.c:441 (sofia/internal/sip:1002@135.240.10.210) State Change CS_REPORTING -> CS_DESTROY 2014-07-21 11:31:01.844183 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/sip:1002@135.240.10.210 [BREAK] 2014-07-21 11:31:01.844183 [DEBUG] switch_core_session.c:1559 Session 32 (sofia/internal/sip:1002@135.240.10.210) Locked, Waiting on external entities 2014-07-21 11:31:01.864127 [DEBUG] switch_ivr_bridge.c:557 sofia/internal/sip:1002@135.240.10.210 ending bridge by request from write function 2014-07-21 11:31:01.864127 [DEBUG] switch_ivr_bridge.c:633 BRIDGE THREAD DONE [sofia/internal/1001@135.252.186.206] 2014-07-21 11:31:01.864127 [DEBUG] switch_ivr_bridge.c:658 Send signal sofia/internal/sip:1002@135.240.10.210 [BREAK] 2014-07-21 11:31:01.864127 [DEBUG] switch_core_session.c:871 Send signal sofia/internal/1001@135.252.186.206 [BREAK] 2014-07-21 11:31:01.864127 [NOTICE] switch_ivr_bridge.c:1569 Hangup sofia/internal/1001@135.252.186.206 [CS_EXECUTE] [NORMAL_CLEARING] 2014-07-21 11:31:01.864127 [DEBUG] switch_channel.c:3183 Send signal sofia/internal/1001@135.252.186.206 [KILL] 2014-07-21 11:31:01.864127 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1001@135.252.186.206 [BREAK] 2014-07-21 11:31:01.864127 [NOTICE] switch_core_session.c:1577 Session 32 (sofia/internal/sip:1002@135.240.10.210) Ended 2014-07-21 11:31:01.864127 [NOTICE] switch_core_session.c:1581 Close Channel sofia/internal/sip:1002@135.240.10.210 [CS_DESTROY] 2014-07-21 11:31:01.864127 [DEBUG] switch_core_session.c:2810 sofia/internal/1001@135.252.186.206 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:478 (sofia/internal/1001@135.252.186.206) State EXECUTE going to sleep 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1001@135.252.186.206) Running State Change CS_HANGUP 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:566 (sofia/internal/sip:1002@135.240.10.210) Callstate Change HANGUP -> DOWN 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/sip:1002@135.240.10.210) Running State Change CS_DESTROY 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:679 (sofia/internal/1001@135.252.186.206) State HANGUP 2014-07-21 11:31:01.864127 [DEBUG] mod_sofia.c:500 sofia/internal/1001@135.252.186.206 Overriding SIP cause 480 with 200 from the other leg 2014-07-21 11:31:01.864127 [DEBUG] mod_sofia.c:506 Channel sofia/internal/1001@135.252.186.206 hanging up, cause: NORMAL_CLEARING 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/sip:1002@135.240.10.210) State DESTROY 2014-07-21 11:31:01.864127 [DEBUG] mod_sofia.c:399 sofia/internal/sip:1002@135.240.10.210 SOFIA DESTROY 2014-07-21 11:31:01.864127 [DEBUG] switch_rtp.c:927 [ zrtp engine]: STOP STREAM ID=20 mode=DH state=ERROR. 2014-07-21 11:31:01.864127 [DEBUG] switch_rtp.c:927 [ zrtp]: Stream ID=0 UNKNOWN switching ---> . 2014-07-21 11:31:01.864127 [DEBUG] switch_rtp.c:927 [ zrtp engine]: STOP STREAM ID=0 mode=UNKNOWN state=NONE. 2014-07-21 11:31:01.864127 [DEBUG] switch_rtp.c:927 [ zrtp engine]: STOP STREAM ID=0 mode=UNKNOWN state=NONE. 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:99 sofia/internal/sip:1002@135.240.10.210 Standard DESTROY 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/sip:1002@135.240.10.210) State DESTROY going to sleep 2014-07-21 11:31:01.864127 [DEBUG] mod_sofia.c:558 Sending BYE to sofia/internal/1001@135.252.186.206 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:48 sofia/internal/1001@135.252.186.206 Standard HANGUP, cause: NORMAL_CLEARING 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:679 (sofia/internal/1001@135.252.186.206) State HANGUP going to sleep 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:690 (sofia/internal/1001@135.252.186.206) Callstate Change ACTIVE -> HANGUP 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:447 (sofia/internal/1001@135.252.186.206) State Change CS_HANGUP -> CS_REPORTING 2014-07-21 11:31:01.864127 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1001@135.252.186.206 [BREAK] 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:415 (sofia/internal/1001@135.252.186.206) Running State Change CS_REPORTING 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:762 (sofia/internal/1001@135.252.186.206) State REPORTING 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:92 sofia/internal/1001@135.252.186.206 Standard REPORTING, cause: NORMAL_CLEARING 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:762 (sofia/internal/1001@135.252.186.206) State REPORTING going to sleep 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:441 (sofia/internal/1001@135.252.186.206) State Change CS_REPORTING -> CS_DESTROY 2014-07-21 11:31:01.864127 [DEBUG] switch_core_session.c:1351 Send signal sofia/internal/1001@135.252.186.206 [BREAK] 2014-07-21 11:31:01.864127 [DEBUG] switch_core_session.c:1559 Session 31 (sofia/internal/1001@135.252.186.206) Locked, Waiting on external entities 2014-07-21 11:31:01.864127 [NOTICE] switch_core_session.c:1577 Session 31 (sofia/internal/1001@135.252.186.206) Ended 2014-07-21 11:31:01.864127 [NOTICE] switch_core_session.c:1581 Close Channel sofia/internal/1001@135.252.186.206 [CS_DESTROY] 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:566 (sofia/internal/1001@135.252.186.206) Callstate Change HANGUP -> DOWN 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/1001@135.252.186.206) Running State Change CS_DESTROY 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/1001@135.252.186.206) State DESTROY 2014-07-21 11:31:01.864127 [DEBUG] mod_sofia.c:399 sofia/internal/1001@135.252.186.206 SOFIA DESTROY 2014-07-21 11:31:01.864127 [DEBUG] switch_rtp.c:927 [ zrtp engine]: STOP STREAM ID=19 mode=DH state=ERROR. 2014-07-21 11:31:01.864127 [DEBUG] switch_rtp.c:927 [ zrtp]: Stream ID=0 UNKNOWN switching ---> . 2014-07-21 11:31:01.864127 [DEBUG] switch_rtp.c:927 [ zrtp engine]: STOP STREAM ID=0 mode=UNKNOWN state=NONE. 2014-07-21 11:31:01.864127 [DEBUG] switch_rtp.c:927 [ zrtp engine]: STOP STREAM ID=0 mode=UNKNOWN state=NONE. 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:99 sofia/internal/1001@135.252.186.206 Standard DESTROY 2014-07-21 11:31:01.864127 [DEBUG] switch_core_state_machine.c:579 (sofia/internal/1001@135.252.186.206) State DESTROY going to sleep