search

sipwise / rtpengine

The Sipwise media proxy for Kamailio
GNU General Public License v3.0
782 stars 368 forks source link

No RTP/SRTP Sent #12

Closed edjames99 closed 10 years ago

edjames99 commented 10 years ago

Hi All, I'm trying to integrate Rtpengine into our MS Lync testing estate (so there's a MS Lync SIP client on the SRTP side and our internal media card on the RTP side) and have got to the point where there are RTP/RTCP (from the media card) and SRTP/SRTCP packets (from the MS Lync SIP client) going into the proxy (both IPV4) but no packets being sent by the proxy. Some info:

  1. The sip/sdp messages look fine either side of the rtpproxy, RTP/AVP on the rtp side and RTP/SAVP on the srtp side plus crypto attributes etc.. look ok.
  2. There's no firewall on the kamailio hosting the Rtpengine or the windows 7 prof workstation which is hosting the virtual kamailio.
  3. Wireshark of the RTP and SRTP packets coming into the proxy show healthy looking packets from both the Lync testing client and the media card.
  4. There are no errors seen in the kamailio logs.

    Our kamailio script entries:

Loadmodule “rtpproxy-ng.so” Modparam(“rtpproxy-ng”, “rtpproxy_sock”, “udp:127.0.0.1:2223”)

request_route

For request from RTP to SRTP with sdp body

Rtpproxy_manage(“froc+Sp”) onreply_route rtpproxy_answer(“-sp”)

For request from SRTP to RTP with sdp body

Rtpproxy_manage(“froc-sp”) Onreply_route

Rtpproxy_answer(“froc+Sp”)

Commands we run at startup:

service mysqld start service kamailio start - - for rtpproxy modprobe xt_MEDIAPROXY iptables –I INPUT –p udp –d 10.1.0.127 –j MEDIAPROXY - -id 0 echo ‘del 0’ > /proc/mediaproxy/control /usr/bin/rtpengine --table=0 - - listen-ng=127.0.0.1:2223 - - tos=184 --pidfile=/var/run/rtpengine.pid - - no-fallback Service mysqld start

Service kamailio start

Any comments, suggestions etc.. as to why there are no packets being sent by the proxy would be welcome. I suspect it might be something obvious relating to config but if not then some pointers to places in the code I could add extra debugging would be helpful.

Thanks Ed James

rfuchs commented 10 years ago

Could you please post the full rtpengine log output for a test call you've made, thanks.

edjames99 commented 10 years ago

Is there an rtpengine specific log as separate from the kamailio log ?

rfuchs commented 10 years ago

Yes, the rtpengine daemon logs separately. It logs to syslog using the "daemon" facility.

edjames99 commented 10 years ago

Please find the log file output for a test call. I tried to get LOG_DEBUG to output (tried defining env variable $DBG, changing the make file to always include -DDEBUG=1 , removing the DEBUG section from iLog & running rtpengine with a --log-level=7) but I couldn't get any LOG_DEBUG output. If you search backwards from the bottom for OUT_DIALOG_FROM_LYNCIT then that's the first call coming in from the SRTP side. Thanks very much for your help it's much appreciated. Ed James

Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[4928]: NOTICE: <core> [main.c:730]: handle_sigs(): Thank you for flying kamailio!!!
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[4938]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[4937]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[4936]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[4935]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[4934]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[4933]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[4932]: INFO: <core> [main.c:841]: sig_usr(): INFO: signal 15 received
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[4928]: ERROR: ctl [ctl.c:379]: mod_destroy(): ERROR: ctl: could not delete unix socket /tmp/kamailio_ctl: Operation not permitted (1)
Jul 24 15:18:03 localhost kamailio: INFO: tls [tls_init.c:385]: init_tls_compression(): tls: init_tls: disabling compression...
Jul 24 15:18:03 localhost kamailio: INFO: <core> [tcp_main.c:4836]: init_tcp(): init_tcp: using epoll_lt as the io watch method (auto detected)
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: rr [../outbound/api.h:54]: ob_load_api(): Failed to import bind_ob
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: rr [rr_mod.c:159]: mod_init(): outbound module not available
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: path [../outbound/api.h:54]: ob_load_api(): Failed to import bind_ob
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: path [path_mod.c:147]: mod_init(): outbound module not available
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_init.c:549]: init_tls_h(): tls: _init_tls_h:  compiled  with  openssl  version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on, compression: on
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_init.c:557]: init_tls_h(): tls: init_tls_h: installed openssl library version "OpenSSL 1.0.1e-fips 11 Feb 2013" (0x1000105f), kerberos support: on,  zlib compression: on#012 compiler: gcc -fPIC -DOPENSSL_PIC -DZLIB -DOPENSSL_THREADS -D_REENTRANT -DDSO_DLFCN -DHAVE_DLFCN_H -DKRB5_MIT -m64 -DL_ENDIAN -DTERMIO -Wall -O2 -g -pipe -Wall -Wp,-D_FORTIFY_SOURCE=2 -fexceptions -fstack-protector --param=ssp-buffer-size=4 -m64 -mtune=generic -Wa,--noexecstack -DPURIFY -DOPENSSL_IA32_SSE2 -DOPENSSL_BN_ASM_MONT -DOPENSSL_BN_ASM_MONT5 -DOPENSSL_BN_ASM_GF2m -DSHA1_ASM -DSHA256_ASM -DSHA512_ASM -DMD5_ASM -DAES_ASM -DVPAES_ASM -DBSAES_ASM -DWHIRLPOOL_ASM -DGHASH_ASM
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: WARNING: tls [tls_init.c:611]: init_tls_h(): tls: openssl bug #1491 (crash/mem leaks on low memory) workaround enabled (on low memory tls operations will fail preemptively) with free memory thresholds 4194304 and 2097152 bytes
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: <core> [cfg/cfg_ctx.c:613]: cfg_set_now(): INFO: cfg_set_now(): tls.low_mem_threshold1 has been changed to 4194304
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: <core> [cfg/cfg_ctx.c:613]: cfg_set_now(): INFO: cfg_set_now(): tls.low_mem_threshold2 has been changed to 2097152
Jul 24 15:18:03 localhost rtpengine[4945]: Got valid command from 127.0.0.1:43833: ping - { "command": "ping" }
Jul 24 15:18:03 localhost rtpengine[4945]: Returning to SIP proxy: d6:result4:ponge
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: rtpproxy-ng [rtpproxy.c:1430]: rtpp_test(): rtp proxy udp:127.0.0.1:2223 found, support for it enabled
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:190]: fill_missing(): TLSs<default>: tls_method=9
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:202]: fill_missing(): TLSs<default>: certificate='/usr/local/etc/kamailio/Kam_CertOnly.pem'
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:209]: fill_missing(): TLSs<default>: ca_list='(null)'
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:216]: fill_missing(): TLSs<default>: crl='(null)'
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:220]: fill_missing(): TLSs<default>: require_certificate=0
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:227]: fill_missing(): TLSs<default>: cipher_list='(null)'
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:234]: fill_missing(): TLSs<default>: private_key='/usr/local/etc/kamailio/Kam_KeyOnly.pem'
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:238]: fill_missing(): TLSs<default>: verify_certificate=0
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:241]: fill_missing(): TLSs<default>: verify_depth=9
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:579]: set_verification(): TLSs<default>: No client certificate required and no checks performed
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:190]: fill_missing(): TLSc<default>: tls_method=9
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:202]: fill_missing(): TLSc<default>: certificate='(null)'
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:209]: fill_missing(): TLSc<default>: ca_list='/usr/local/etc/kamailio/RS001738_CA.pem'
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:216]: fill_missing(): TLSc<default>: crl='(null)'
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:220]: fill_missing(): TLSc<default>: require_certificate=1
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:227]: fill_missing(): TLSc<default>: cipher_list='(null)'
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:234]: fill_missing(): TLSc<default>: private_key='(null)'
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:238]: fill_missing(): TLSc<default>: verify_certificate=1
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:241]: fill_missing(): TLSc<default>: verify_depth=9
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: tls [tls_domain.c:564]: set_verification(): TLSc<default>: Server MUST present valid certificate
Jul 24 15:18:03 localhost rtpengine[4945]: Got valid command from 127.0.0.1:32775: ping - { "command": "ping" }
Jul 24 15:18:03 localhost rtpengine[4945]: Returning to SIP proxy: d6:result4:ponge
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5028]: INFO: rtpproxy-ng [rtpproxy.c:1430]: rtpp_test(): rtp proxy udp:127.0.0.1:2223 found, support for it enabled
Jul 24 15:18:03 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42773: ping - { "command": "ping" }
Jul 24 15:18:03 localhost rtpengine[4945]: Returning to SIP proxy: d6:result4:ponge
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5033]: INFO: rtpproxy-ng [rtpproxy.c:1430]: rtpp_test(): rtp proxy udp:127.0.0.1:2223 found, support for it enabled
Jul 24 15:18:03 localhost rtpengine[4945]: Got valid command from 127.0.0.1:51022: ping - { "command": "ping" }
Jul 24 15:18:03 localhost rtpengine[4945]: Returning to SIP proxy: d6:result4:ponge
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5032]: INFO: rtpproxy-ng [rtpproxy.c:1430]: rtpp_test(): rtp proxy udp:127.0.0.1:2223 found, support for it enabled
Jul 24 15:18:03 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: ping - { "command": "ping" }
Jul 24 15:18:03 localhost rtpengine[4945]: Returning to SIP proxy: d6:result4:ponge
Jul 24 15:18:03 localhost rtpengine[4945]: Got valid command from 127.0.0.1:47390: ping - { "command": "ping" }
Jul 24 15:18:03 localhost rtpengine[4945]: Returning to SIP proxy: d6:result4:ponge
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5035]: INFO: rtpproxy-ng [rtpproxy.c:1430]: rtpp_test(): rtp proxy udp:127.0.0.1:2223 found, support for it enabled
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5035]: INFO: ctl [io_listener.c:225]: io_listen_loop(): io_listen_loop:  using epoll_lt io watch method (config)
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5036]: INFO: rtpproxy-ng [rtpproxy.c:1430]: rtpp_test(): rtp proxy udp:127.0.0.1:2223 found, support for it enabled
Jul 24 15:18:03 localhost rtpengine[4945]: Got valid command from 127.0.0.1:47165: ping - { "command": "ping" }
Jul 24 15:18:03 localhost rtpengine[4945]: Returning to SIP proxy: d6:result4:ponge
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5039]: INFO: rtpproxy-ng [rtpproxy.c:1430]: rtpp_test(): rtp proxy udp:127.0.0.1:2223 found, support for it enabled
Jul 24 15:18:03 localhost rtpengine[4945]: Got valid command from 127.0.0.1:43882: ping - { "command": "ping" }
Jul 24 15:18:03 localhost rtpengine[4945]: Returning to SIP proxy: d6:result4:ponge
Jul 24 15:18:03 localhost /usr/local/sbin/kamailio[5040]: INFO: rtpproxy-ng [rtpproxy.c:1430]: rtpp_test(): rtp proxy udp:127.0.0.1:2223 found, support for it enabled
Jul 24 15:18:07 localhost /usr/local/sbin/kamailio[5036]: NOTICE: <script>: Enter main request route
Jul 24 15:18:07 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: Main request route OPTIONS
Jul 24 15:18:07 localhost /usr/local/sbin/kamailio[5039]: NOTICE: <script>: Enter main request route
Jul 24 15:18:07 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: Main request route OPTIONS
Jul 24 15:18:09 localhost /usr/local/sbin/kamailio[5036]: NOTICE: <script>: Enter main request route
Jul 24 15:18:09 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: Main request route INVITE
Jul 24 15:18:09 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: OUT_DIALOG_FROM_LYNCIT
Jul 24 15:18:09 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: offer - { "sdp": "v=0#015#012o=- 0 0 IN IP4 192.168.2.106#015#012s=session#015#012c=IN IP4 192.168.2.106#015#012b=CT:100000#015#012t=0 0#015#012m=audio 33042 RTP/SAVP 0 8 97 101 13#015#012c=IN IP4 192.168.2.106#015#012a=rtcp:33043#015#012a=sendrecv#015#012a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:yTsMgQAYfsg5Eq8u9LJLKOcIafzyzK19UwssmASF|2^31|1:1#015#012a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:A1Jzi0OLDgUB6l8uXfp7vAyNTzb4w8CcwjRrPS7G|2^31#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=label:main-audio#015#012a=rtcp-rsize#015#012a=x-ssrc-range:89-89#015#012a=x-source:main-audio#015#012a=rtcp-fb:\* x-message app recv:dsh#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=rtpmap:13 CN/8000#015#012", "ICE": "remove", "flags": [ "force", "trust-address" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/AVP", "call-id": "2cb67bfe-5a85-4010-8e20-572bd9cd24f6", "received-from": [ "IP4", "192.168.2.106" ], "from-tag": "a5bc7e554", "command": "offer" }
Jul 24 15:18:09 localhost rtpengine[4945]: ERJ LOG_ERROR parse crypto 1 31
Jul 24 15:18:09 localhost rtpengine[4945]: ERJ LOG_INFO parse crypto 1 31
Jul 24 15:18:09 localhost rtpengine[4945]: ERJ parse crypto 2 2147483648
Jul 24 15:18:09 localhost rtpengine[4945]: ERJ LOG_ERROR parse crypto 1 31
Jul 24 15:18:09 localhost rtpengine[4945]: ERJ LOG_INFO parse crypto 1 31
Jul 24 15:18:09 localhost rtpengine[4945]: ERJ parse crypto 2 2147483648
Jul 24 15:18:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] Creating new call
Jul 24 15:18:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] Returning to SIP proxy: d3:sdp422:v=0#015#012o=- 0 0 IN IP4 10.1.0.127#015#012s=session#015#012c=IN IP4 10.1.0.127#015#012b=CT:100000#015#012t=0 0#015#012m=audio 30000 RTP/AVP 0 8 97 101 13#015#012c=IN IP4 10.1.0.127#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=label:main-audio#015#012a=rtcp-rsize#015#012a=x-ssrc-range:89-89#015#012a=x-source:main-audio#015#012a=rtcp-fb:\* x-message app recv:dsh#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=rtpmap:13 CN/8000#015#012a=sendrecv#015#012a=rtcp:30001#015#0126:result2:oke
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: NOTICE: <script>: Enter main request route
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: Main request route INVITE
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: OUT_DIALOG_TO_LYNCIT
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: sending to 192.168.2.106:5076 ERJ01
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: ERJ05 - out dialog to lyncit
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: ERJ06 - out dialog to lyncit INVITE
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: ERJ07 - out dialog to lyncit INVITE sdp
Jul 24 15:18:54 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: offer - { "sdp": "v=0#015#012o=Redwood_INX 515320 515320 IN IP4 10.1.0.121#015#012s=Redwood Media Server#015#012c=IN IP4 10.1.0.121#015#012t=0 0#015#012m=audio 19130 RTP/AVP 8 97 96 13#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:96 telephone-event/8000#015#012a=fmtp:96 0-16#015#012a=rtpmap:13 CN/8000#015#012a=ptime:20#015#012a=sendrecv#015#012a=rtcp:19131#015#012a=label:main-audio#015#012", "ICE": "force", "flags": [ "force", "trust-address" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/SAVP", "call-id": "YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.", "received-from": [ "IP4", "10.1.0.119" ], "from-tag": "422ab553", "command": "offer" }
Jul 24 15:18:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] Creating new call
Jul 24 15:18:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] Returning to SIP proxy: d3:sdp714:v=0#015#012o=Redwood_INX 515320 515320 IN IP4 10.1.0.127#015#012s=Redwood Media Server#015#012c=IN IP4 10.1.0.127#015#012t=0 0#015#012a=ice-lite#015#012m=audio 30004 RTP/SAVP 8 97 96 13#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:96 telephone-event/8000#015#012a=fmtp:96 0-16#015#012a=rtpmap:13 CN/8000#015#012a=ptime:20#015#012a=label:main-audio#015#012a=sendrecv#015#012a=rtcp:30005#015#012a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:45ddxkGAgIgJY7MlhjUQUDYLpiWyWuG/GN7FY6rr#015#012a=setup:actpass#015#012a=fingerprint:sha-1 6C:C3:2F:5F:72:6E:EE:76:15:7E:72:87:29:38:80:4F:BD:03:71:62#015#012a=ice-ufrag:0xOvNbVt#015#012a=ice-pwd:7SyAP39k1JtcwdUzJWwe7oB7TpDG#015#012a=candidate:GJzGDWWqDztv0n8z 1 UDP 2130706432 10.1.0.127 30004 typ host#015#012a=candidate:GJzGDWWqDztv0n8z 2 UDP 2130706431 10.1.0.127 30005 typ host#015#0126:result2:oke
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: ERJ21 - 183 reply to INVITE to LYNCIT
Jul 24 15:18:54 localhost rtpengine[4945]: Got valid command from 127.0.0.1:47165: answer - { "sdp": "v=0#015#012o=- 0 0 IN IP4 192.168.2.106#015#012s=session#015#012c=IN IP4 192.168.2.106#015#012b=CT:100000#015#012t=0 0#015#012m=audio 33488 RTP/SAVP 8 97 96 13#015#012c=IN IP4 192.168.2.106#015#012a=rtcp:33489#015#012a=sendrecv#015#012a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:mMRsrZmELQh9fqusFxkwdue5wSmrLnMCRLngxH0A|2^31|1:1#015#012a=rtpmap:8 PCMA/8000#015#012a=ptime:20#015#012a=label:main-audio#015#012a=x-ssrc-range:91-91#015#012a=x-source:main-audio#015#012a=rtcp-fb:\* x-message app recv:dsh#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:96 telephone-event/8000#015#012a=fmtp:96 0-16#015#012a=rtpmap:13 CN/8000#015#012", "ICE": "remove", "transport-protocol": "RTP/AVP", "call-id": "YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.", "received-from": [ "IP4", "192.168.2.106" ], "from-tag": "422ab553", "to-tag": "ad508ba5ae", "command": "answer" }
Jul 24 15:18:54 localhost rtpengine[4945]: ERJ LOG_ERROR parse crypto 1 31
Jul 24 15:18:54 localhost rtpengine[4945]: ERJ LOG_INFO parse crypto 1 31
Jul 24 15:18:54 localhost rtpengine[4945]: ERJ parse crypto 2 2147483648
Jul 24 15:18:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] Returning to SIP proxy: d3:sdp399:v=0#015#012o=- 0 0 IN IP4 192.168.2.106#015#012s=session#015#012c=IN IP4 192.168.2.106#015#012b=CT:100000#015#012t=0 0#015#012m=audio 30006 RTP/AVP 8 97 96 13#015#012c=IN IP4 10.1.0.127#015#012a=rtpmap:8 PCMA/8000#015#012a=ptime:20#015#012a=label:main-audio#015#012a=x-ssrc-range:91-91#015#012a=x-source:main-audio#015#012a=rtcp-fb:\* x-message app recv:dsh#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:96 telephone-event/8000#015#012a=fmtp:96 0-16#015#012a=rtpmap:13 CN/8000#015#012a=sendrecv#015#012a=rtcp:30007#015#0126:result2:oke
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: ERJ21 - 183 reply to INVITE to LYNCIT
Jul 24 15:18:54 localhost rtpengine[4945]: Got valid command from 127.0.0.1:47165: answer - { "sdp": "v=0#015#012o=- 0 0 IN IP4 192.168.2.106#015#012s=session#015#012c=IN IP4 192.168.2.106#015#012b=CT:100000#015#012t=0 0#015#012m=audio 33044 RTP/SAVP 8 97 96 13#015#012c=IN IP4 192.168.2.106#015#012a=rtcp:33045#015#012a=sendrecv#015#012a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:ylCL8bd0++YSTxeOKthU+Bmo6ZAVwEfPdxshwVZi|2^31|1:1#015#012a=rtpmap:8 PCMA/8000#015#012a=ptime:20#015#012a=label:main-audio#015#012a=x-ssrc-range:90-90#015#012a=x-source:main-audio#015#012a=rtcp-fb:\* x-message app recv:dsh#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:96 telephone-event/8000#015#012a=fmtp:96 0-16#015#012a=rtpmap:13 CN/8000#015#012", "ICE": "remove", "transport-protocol": "RTP/AVP", "call-id": "YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.", "received-from": [ "IP4", "192.168.2.106" ], "from-tag": "422ab553", "to-tag": "cdbc926be2", "command": "answer" }
Jul 24 15:18:54 localhost rtpengine[4945]: ERJ LOG_ERROR parse crypto 1 31
Jul 24 15:18:54 localhost rtpengine[4945]: ERJ LOG_INFO parse crypto 1 31
Jul 24 15:18:54 localhost rtpengine[4945]: ERJ parse crypto 2 2147483648
Jul 24 15:18:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] Returning to SIP proxy: d3:sdp399:v=0#015#012o=- 0 0 IN IP4 192.168.2.106#015#012s=session#015#012c=IN IP4 192.168.2.106#015#012b=CT:100000#015#012t=0 0#015#012m=audio 30008 RTP/AVP 8 97 96 13#015#012c=IN IP4 10.1.0.127#015#012a=rtpmap:8 PCMA/8000#015#012a=ptime:20#015#012a=label:main-audio#015#012a=x-ssrc-range:90-90#015#012a=x-source:main-audio#015#012a=rtcp-fb:\* x-message app recv:dsh#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:96 telephone-event/8000#015#012a=fmtp:96 0-16#015#012a=rtpmap:13 CN/8000#015#012a=sendrecv#015#012a=rtcp:30009#015#0126:result2:oke
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: NOTICE: <script>: Enter main request route
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: Main request route PRACK
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: IN_DIALOG_TO_LYNCIT
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: ERJ08 - IN_DIALOG_TO_LYNCIT PRACK
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: ERJ10 - IN_DIALOG_TO_LYNCIT NO sdp
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: ERJ20 - 183 reply to INVITE from LYNCIT
Jul 24 15:18:54 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: answer - { "sdp": "v=0#015#012o=Redwood_INX 514876 514876 IN IP4 10.1.0.121#015#012s=Redwood Media Server#015#012c=IN IP4 10.1.0.121#015#012t=0 0#015#012m=audio 19110 RTP/AVP 8 97 101 13#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=rtpmap:13 CN/8000#015#012a=sendrecv#015#012", "ICE": "force", "flags": [ "force", "trust-address" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/SAVP", "call-id": "2cb67bfe-5a85-4010-8e20-572bd9cd24f6", "received-from": [ "IP4", "10.1.0.119" ], "from-tag": "a5bc7e554", "to-tag": "f242e810", "command": "answer" }
Jul 24 15:18:54 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] Returning to SIP proxy: d3:sdp587:v=0#015#012o=Redwood_INX 514876 514876 IN IP4 10.1.0.127#015#012s=Redwood Media Server#015#012c=IN IP4 10.1.0.127#015#012t=0 0#015#012a=ice-lite#015#012m=audio 30002 RTP/SAVP 8 97 101 13#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=rtpmap:13 CN/8000#015#012a=sendrecv#015#012a=rtcp:30003#015#012a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:KpirdRvhc8KepnqsDz5gnbNuDOiUWuIeUsdD1y5i#015#012a=ice-ufrag:xC3Cfqis#015#012a=ice-pwd:CYM7EP5wmggr9X3fL0XGR1dnCgZR#015#012a=candidate:GJzGDWWqDztv0n8z 1 UDP 2130706432 10.1.0.127 30002 typ host#015#012a=candidate:GJzGDWWqDztv0n8z 2 UDP 2130706431 10.1.0.127 30003 typ host#015#0126:result2:oke
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5039]: NOTICE: <script>: Enter main request route
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: Main request route PRACK
Jul 24 15:18:54 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: IN_DIALOG_FROM_LYNCIT
Jul 24 15:19:02 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: ERJ21 - 183 reply to INVITE to LYNCIT
Jul 24 15:19:02 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: answer - { "sdp": "v=0#015#012o=- 0 0 IN IP4 192.168.2.106#015#012s=session#015#012c=IN IP4 192.168.2.106#015#012b=CT:100000#015#012t=0 0#015#012m=audio 33044 RTP/SAVP 8 97 96 13#015#012c=IN IP4 192.168.2.106#015#012a=rtcp:33045#015#012a=sendrecv#015#012a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:ylCL8bd0++YSTxeOKthU+Bmo6ZAVwEfPdxshwVZi|2^31|1:1#015#012a=rtpmap:8 PCMA/8000#015#012a=ptime:20#015#012a=label:main-audio#015#012a=x-ssrc-range:90-90#015#012a=x-source:main-audio#015#012a=rtcp-fb:\* x-message app recv:dsh#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:96 telephone-event/8000#015#012a=fmtp:96 0-16#015#012a=rtpmap:13 CN/8000#015#012", "ICE": "remove", "transport-protocol": "RTP/AVP", "call-id": "YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.", "received-from": [ "IP4", "192.168.2.106" ], "from-tag": "422ab553", "to-tag": "cdbc926be2", "command": "answer" }
Jul 24 15:19:02 localhost rtpengine[4945]: ERJ LOG_ERROR parse crypto 1 31
Jul 24 15:19:02 localhost rtpengine[4945]: ERJ LOG_INFO parse crypto 1 31
Jul 24 15:19:02 localhost rtpengine[4945]: ERJ parse crypto 2 2147483648
Jul 24 15:19:02 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] Returning to SIP proxy: d3:sdp399:v=0#015#012o=- 0 0 IN IP4 192.168.2.106#015#012s=session#015#012c=IN IP4 192.168.2.106#015#012b=CT:100000#015#012t=0 0#015#012m=audio 30008 RTP/AVP 8 97 96 13#015#012c=IN IP4 10.1.0.127#015#012a=rtpmap:8 PCMA/8000#015#012a=ptime:20#015#012a=label:main-audio#015#012a=x-ssrc-range:90-90#015#012a=x-source:main-audio#015#012a=rtcp-fb:\* x-message app recv:dsh#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:96 telephone-event/8000#015#012a=fmtp:96 0-16#015#012a=rtpmap:13 CN/8000#015#012a=sendrecv#015#012a=rtcp:30009#015#0126:result2:oke
Jul 24 15:19:02 localhost /usr/local/sbin/kamailio[5039]: NOTICE: <script>: Enter main request route
Jul 24 15:19:02 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: Main request route ACK
Jul 24 15:19:02 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: IN_DIALOG_TO_LYNCIT
Jul 24 15:19:02 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: ERJ10 - IN_DIALOG_TO_LYNCIT NO sdp
Jul 24 15:19:02 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: ERJ20 - 183 reply to INVITE from LYNCIT
Jul 24 15:19:02 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: answer - { "sdp": "v=0#015#012o=Redwood_INX 514876 514876 IN IP4 10.1.0.121#015#012s=Redwood Media Server#015#012c=IN IP4 10.1.0.121#015#012t=0 0#015#012m=audio 19110 RTP/AVP 8 97 101 13#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=rtpmap:13 CN/8000#015#012a=sendrecv#015#012", "ICE": "force", "flags": [ "force", "trust-address" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/SAVP", "call-id": "2cb67bfe-5a85-4010-8e20-572bd9cd24f6", "received-from": [ "IP4", "10.1.0.119" ], "from-tag": "a5bc7e554", "to-tag": "f242e810", "command": "answer" }
Jul 24 15:19:02 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] Returning to SIP proxy: d3:sdp587:v=0#015#012o=Redwood_INX 514876 514876 IN IP4 10.1.0.127#015#012s=Redwood Media Server#015#012c=IN IP4 10.1.0.127#015#012t=0 0#015#012a=ice-lite#015#012m=audio 30002 RTP/SAVP 8 97 101 13#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:97 red/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=rtpmap:13 CN/8000#015#012a=sendrecv#015#012a=rtcp:30003#015#012a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:KpirdRvhc8KepnqsDz5gnbNuDOiUWuIeUsdD1y5i#015#012a=ice-ufrag:xC3Cfqis#015#012a=ice-pwd:CYM7EP5wmggr9X3fL0XGR1dnCgZR#015#012a=candidate:GJzGDWWqDztv0n8z 1 UDP 2130706432 10.1.0.127 30002 typ host#015#012a=candidate:GJzGDWWqDztv0n8z 2 UDP 2130706431 10.1.0.127 30003 typ host#015#0126:result2:oke
Jul 24 15:19:02 localhost /usr/local/sbin/kamailio[5039]: NOTICE: <script>: Enter main request route
Jul 24 15:19:02 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: Main request route ACK
Jul 24 15:19:02 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: IN_DIALOG_FROM_LYNCIT
Jul 24 15:19:02 localhost /usr/local/sbin/kamailio[5039]: NOTICE: <script>: Enter main request route
Jul 24 15:19:02 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: Main request route BYE
Jul 24 15:19:02 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: IN_DIALOG_FROM_LYNCIT
Jul 24 15:19:03 localhost /usr/local/sbin/kamailio[5039]: NOTICE: <script>: Enter main request route
Jul 24 15:19:03 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: Main request route BYE
Jul 24 15:19:03 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: IN_DIALOG_TO_LYNCIT
Jul 24 15:19:03 localhost /usr/local/sbin/kamailio[5039]: INFO: <script>: ERJ10 - IN_DIALOG_TO_LYNCIT NO sdp
Jul 24 15:19:07 localhost /usr/local/sbin/kamailio[5036]: NOTICE: <script>: Enter main request route
Jul 24 15:19:07 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: Main request route OPTIONS
Jul 24 15:19:07 localhost /usr/local/sbin/kamailio[5036]: NOTICE: <script>: Enter main request route
Jul 24 15:19:07 localhost /usr/local/sbin/kamailio[5036]: INFO: <script>: Main request route OPTIONS
Jul 24 15:19:09 localhost rtpengine[4945]: Closing call branch due to timeout
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] Final packet stats:
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] --- Tag 'f242e810', created 1:00 ago, in dialogue with 'a5bc7e554'
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] ------ Media #1, port 30002 <>   192.168.2.106:33042, 0 p, 0 b, 0 e
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] ------ Media #1, port 30003 <>   192.168.2.106:33043 (RTCP), 0 p, 0 b, 0 e
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] --- Tag 'a5bc7e554', created 1:00 ago, in dialogue with 'f242e810'
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] ------ Media #1, port 30000 <>      10.1.0.121:19110, 0 p, 0 b, 0 e
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] ------ Media #1, port 30001 <>      10.1.0.121:19111 (RTCP), 0 p, 0 b, 0 e
Jul 24 15:19:54 localhost rtpengine[4945]: Closing call branch due to timeout
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] Final packet stats:
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] --- Tag 'cdbc926be2', created 1:00 ago, in dialogue with '422ab553'
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30008 <>            [::]:0    , 0 p, 0 b, 0 e
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30009 <>            [::]:0     (RTCP), 0 p, 0 b, 0 e
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] --- Tag 'ad508ba5ae', created 1:00 ago, in dialogue with '422ab553'
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30006 <>      10.1.0.121:19130, 0 p, 0 b, 0 e
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30007 <>      10.1.0.121:19131 (RTCP), 0 p, 0 b, 0 e
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] --- Tag '422ab553', created 1:00 ago, in dialogue with 'cdbc926be2'
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30004 <>   192.168.2.106:33044, 0 p, 0 b, 0 e
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30005 <>   192.168.2.106:33045 (RTCP), 0 p, 0 b, 0 e
rfuchs commented 10 years ago

Sorry but this doesn't contain any useful information. The log you posted doesn't contain any calls.

edjames99 commented 10 years ago

There are two calls in the log file as follows:

First Call - Search for "OUT_DIALOG_FROM_LYNCIT" - some call details: Jul 24 15:18:09 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: offer... call-id = 2cb67bfe-5a85-4010-8e20-572bd9cd24f6 "received-from": [ "IP4", "192.168.2.106" ] result2:oke

Second Call - Search for "OUT_DIALOG_TO_LYNCIT - some call details: Jul 24 15:18:54 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: offer... "call-id": "YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU. "received-from": [ "IP4", "10.1.0.119" ] result2:oke

I assume at this point rtpengine has knowledge of both calls (the SRTP from 192.168.2.106 and the RTP from 10.1.0.119) as it has modified the sdp offer in both SIP INVITE messages. What were you looking for in the log ? What log entries were you expecting to see that weren't there ?

rfuchs commented 10 years ago

Yes, those would be the lines. Search the page yourself, they don't appear in what you posted.

edjames99 commented 10 years ago

I think you have to hit the Edit Comment pencil icon then do a select all and then paste to see the entire contents of the post.

rfuchs commented 10 years ago

Ah yes, you're right. Silly github, truncating comments like that. Reproducing the relevant log lines here, reformatted for clarity:

Jul 24 15:18:09 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: offer - { "sdp": "v=0
o=- 0 0 IN IP4 192.168.2.106
s=session
c=IN IP4 192.168.2.106
b=CT:100000
t=0 0
m=audio 33042 RTP/SAVP 0 8 97 101 13
c=IN IP4 192.168.2.106
a=rtcp:33043
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:yTsMgQAYfsg5Eq8u9LJLKOcIafzyzK19UwssmASF|2^31|1:1
a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:A1Jzi0OLDgUB6l8uXfp7vAyNTzb4w8CcwjRrPS7G|2^31
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=label:main-audio
a=rtcp-rsize
a=x-ssrc-range:89-89
a=x-source:main-audio
a=rtcp-fb:* x-message app recv:dsh
a=rtpmap:97 red/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
", "ICE": "remove", "flags": [ "force", "trust-address" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/AVP", "call-id": "2cb67bfe-5a85-4010-8e20-572bd9cd24f6", "received-from": [ "IP4", "192.168.2.106" ], "from-tag": "a5bc7e554", "command": "offer" }

Jul 24 15:18:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] Returning to SIP proxy: d3:sdp422:v=0
o=- 0 0 IN IP4 10.1.0.127
s=session
c=IN IP4 10.1.0.127
b=CT:100000
t=0 0
m=audio 30000 RTP/AVP 0 8 97 101 13
c=IN IP4 10.1.0.127
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=label:main-audio
a=rtcp-rsize
a=x-ssrc-range:89-89
a=x-source:main-audio
a=rtcp-fb:* x-message app recv:dsh
a=rtpmap:97 red/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=sendrecv
a=rtcp:30001
6:result2:oke

Jul 24 15:18:54 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: offer - { "sdp": "v=0
o=Redwood_INX 515320 515320 IN IP4 10.1.0.121
s=Redwood Media Server
c=IN IP4 10.1.0.121
t=0 0
m=audio 19130 RTP/AVP 8 97 96 13
a=rtpmap:8 PCMA/8000
a=rtpmap:97 red/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv
a=rtcp:19131
a=label:main-audio
", "ICE": "force", "flags": [ "force", "trust-address" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/SAVP", "call-id": "YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.", "received-from": [ "IP4", "10.1.0.119" ], "from-tag": "422ab553", "command": "offer" }

Jul 24 15:18:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] Returning to SIP proxy: d3:sdp714:v=0
o=Redwood_INX 515320 515320 IN IP4 10.1.0.127
s=Redwood Media Server
c=IN IP4 10.1.0.127
t=0 0
a=ice-lite
m=audio 30004 RTP/SAVP 8 97 96 13
a=rtpmap:8 PCMA/8000
a=rtpmap:97 red/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=label:main-audio
a=sendrecv
a=rtcp:30005
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:45ddxkGAgIgJY7MlhjUQUDYLpiWyWuG/GN7FY6rr
a=setup:actpass
a=fingerprint:sha-1 6C:C3:2F:5F:72:6E:EE:76:15:7E:72:87:29:38:80:4F:BD:03:71:62
a=ice-ufrag:0xOvNbVt
a=ice-pwd:7SyAP39k1JtcwdUzJWwe7oB7TpDG
a=candidate:GJzGDWWqDztv0n8z 1 UDP 2130706432 10.1.0.127 30004 typ host
a=candidate:GJzGDWWqDztv0n8z 2 UDP 2130706431 10.1.0.127 30005 typ host
6:result2:oke

Jul 24 15:18:54 localhost rtpengine[4945]: Got valid command from 127.0.0.1:47165: answer - { "sdp": "v=0
o=- 0 0 IN IP4 192.168.2.106
s=session
c=IN IP4 192.168.2.106
b=CT:100000
t=0 0
m=audio 33488 RTP/SAVP 8 97 96 13
c=IN IP4 192.168.2.106
a=rtcp:33489
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:mMRsrZmELQh9fqusFxkwdue5wSmrLnMCRLngxH0A|2^31|1:1
a=rtpmap:8 PCMA/8000
a=ptime:20
a=label:main-audio
a=x-ssrc-range:91-91
a=x-source:main-audio
a=rtcp-fb:* x-message app recv:dsh
a=rtpmap:97 red/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=rtpmap:13 CN/8000
", "ICE": "remove", "transport-protocol": "RTP/AVP", "call-id": "YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.", "received-from": [ "IP4", "192.168.2.106" ], "from-tag": "422ab553", "to-tag": "ad508ba5ae", "command": "answer" }

Jul 24 15:18:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] Returning to SIP proxy: d3:sdp399:v=0
o=- 0 0 IN IP4 192.168.2.106
s=session
c=IN IP4 192.168.2.106
b=CT:100000
t=0 0
m=audio 30006 RTP/AVP 8 97 96 13
c=IN IP4 10.1.0.127
a=rtpmap:8 PCMA/8000
a=ptime:20
a=label:main-audio
a=x-ssrc-range:91-91
a=x-source:main-audio
a=rtcp-fb:* x-message app recv:dsh
a=rtpmap:97 red/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=rtpmap:13 CN/8000
a=sendrecv
a=rtcp:30007
6:result2:oke

Jul 24 15:18:54 localhost rtpengine[4945]: Got valid command from 127.0.0.1:47165: answer - { "sdp": "v=0
o=- 0 0 IN IP4 192.168.2.106
s=session
c=IN IP4 192.168.2.106
b=CT:100000
t=0 0
m=audio 33044 RTP/SAVP 8 97 96 13
c=IN IP4 192.168.2.106
a=rtcp:33045
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:ylCL8bd0++YSTxeOKthU+Bmo6ZAVwEfPdxshwVZi|2^31|1:1
a=rtpmap:8 PCMA/8000
a=ptime:20
a=label:main-audio
a=x-ssrc-range:90-90
a=x-source:main-audio
a=rtcp-fb:* x-message app recv:dsh
a=rtpmap:97 red/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=rtpmap:13 CN/8000
", "ICE": "remove", "transport-protocol": "RTP/AVP", "call-id": "YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.", "received-from": [ "IP4", "192.168.2.106" ], "from-tag": "422ab553", "to-tag": "cdbc926be2", "command": "answer" }

Jul 24 15:18:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] Returning to SIP proxy: d3:sdp399:v=0
o=- 0 0 IN IP4 192.168.2.106
s=session
c=IN IP4 192.168.2.106
b=CT:100000
t=0 0
m=audio 30008 RTP/AVP 8 97 96 13
c=IN IP4 10.1.0.127
a=rtpmap:8 PCMA/8000
a=ptime:20
a=label:main-audio
a=x-ssrc-range:90-90
a=x-source:main-audio
a=rtcp-fb:* x-message app recv:dsh
a=rtpmap:97 red/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=rtpmap:13 CN/8000
a=sendrecv
a=rtcp:30009
6:result2:oke

Jul 24 15:18:54 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: answer - { "sdp": "v=0
o=Redwood_INX 514876 514876 IN IP4 10.1.0.121
s=Redwood Media Server
c=IN IP4 10.1.0.121
t=0 0
m=audio 19110 RTP/AVP 8 97 101 13
a=rtpmap:8 PCMA/8000
a=rtpmap:97 red/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=sendrecv
", "ICE": "force", "flags": [ "force", "trust-address" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/SAVP", "call-id": "2cb67bfe-5a85-4010-8e20-572bd9cd24f6", "received-from": [ "IP4", "10.1.0.119" ], "from-tag": "a5bc7e554", "to-tag": "f242e810", "command": "answer" }

Jul 24 15:18:54 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] Returning to SIP proxy: d3:sdp587:v=0
o=Redwood_INX 514876 514876 IN IP4 10.1.0.127
s=Redwood Media Server
c=IN IP4 10.1.0.127
t=0 0
a=ice-lite
m=audio 30002 RTP/SAVP 8 97 101 13
a=rtpmap:8 PCMA/8000
a=rtpmap:97 red/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=sendrecv
a=rtcp:30003
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:KpirdRvhc8KepnqsDz5gnbNuDOiUWuIeUsdD1y5i
a=ice-ufrag:xC3Cfqis
a=ice-pwd:CYM7EP5wmggr9X3fL0XGR1dnCgZR
a=candidate:GJzGDWWqDztv0n8z 1 UDP 2130706432 10.1.0.127 30002 typ host
a=candidate:GJzGDWWqDztv0n8z 2 UDP 2130706431 10.1.0.127 30003 typ host
6:result2:oke

Jul 24 15:19:02 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: answer - { "sdp": "v=0
o=- 0 0 IN IP4 192.168.2.106
s=session
c=IN IP4 192.168.2.106
b=CT:100000
t=0 0
m=audio 33044 RTP/SAVP 8 97 96 13
c=IN IP4 192.168.2.106
a=rtcp:33045
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:ylCL8bd0++YSTxeOKthU+Bmo6ZAVwEfPdxshwVZi|2^31|1:1
a=rtpmap:8 PCMA/8000
a=ptime:20
a=label:main-audio
a=x-ssrc-range:90-90
a=x-source:main-audio
a=rtcp-fb:* x-message app recv:dsh
a=rtpmap:97 red/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=rtpmap:13 CN/8000
", "ICE": "remove", "transport-protocol": "RTP/AVP", "call-id": "YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.", "received-from": [ "IP4", "192.168.2.106" ], "from-tag": "422ab553", "to-tag": "cdbc926be2", "command": "answer" }

Jul 24 15:19:02 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] Returning to SIP proxy: d3:sdp399:v=0
o=- 0 0 IN IP4 192.168.2.106
s=session
c=IN IP4 192.168.2.106
b=CT:100000
t=0 0
m=audio 30008 RTP/AVP 8 97 96 13
c=IN IP4 10.1.0.127
a=rtpmap:8 PCMA/8000
a=ptime:20
a=label:main-audio
a=x-ssrc-range:90-90
a=x-source:main-audio
a=rtcp-fb:* x-message app recv:dsh
a=rtpmap:97 red/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=rtpmap:13 CN/8000
a=sendrecv
a=rtcp:30009
6:result2:oke

Jul 24 15:19:02 localhost rtpengine[4945]: Got valid command from 127.0.0.1:42187: answer - { "sdp": "v=0
o=Redwood_INX 514876 514876 IN IP4 10.1.0.121
s=Redwood Media Server
c=IN IP4 10.1.0.121
t=0 0
m=audio 19110 RTP/AVP 8 97 101 13
a=rtpmap:8 PCMA/8000
a=rtpmap:97 red/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=sendrecv
", "ICE": "force", "flags": [ "force", "trust-address" ], "replace": [ "origin", "session-connection" ], "transport-protocol": "RTP/SAVP", "call-id": "2cb67bfe-5a85-4010-8e20-572bd9cd24f6", "received-from": [ "IP4", "10.1.0.119" ], "from-tag": "a5bc7e554", "to-tag": "f242e810", "command": "answer" }

Jul 24 15:19:02 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] Returning to SIP proxy: d3:sdp587:v=0
o=Redwood_INX 514876 514876 IN IP4 10.1.0.127
s=Redwood Media Server
c=IN IP4 10.1.0.127
t=0 0
a=ice-lite
m=audio 30002 RTP/SAVP 8 97 101 13
a=rtpmap:8 PCMA/8000
a=rtpmap:97 red/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=sendrecv
a=rtcp:30003
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:KpirdRvhc8KepnqsDz5gnbNuDOiUWuIeUsdD1y5i
a=ice-ufrag:xC3Cfqis
a=ice-pwd:CYM7EP5wmggr9X3fL0XGR1dnCgZR
a=candidate:GJzGDWWqDztv0n8z 1 UDP 2130706432 10.1.0.127 30002 typ host
a=candidate:GJzGDWWqDztv0n8z 2 UDP 2130706431 10.1.0.127 30003 typ host
6:result2:oke
rfuchs commented 10 years ago

So we have...

First call, 2cb67bfe-5a85-4010-8e20-572bd9cd24f6

[SRTP] 192.168.2.106:33042 <> 30002 / 30000 <> 10.1.0.121:19110 [RTP]

IOW, packets received on port 30000 are sent out on port 30002 to side A, and packets received on port 30002 are sent out on port 30000 to side B.

Second call, YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU

[RTP] 10.1.0.121:19130 <> 30006 / 30004 <> 192.168.2.106:33488 [SRTP] then [RTP] 10.1.0.121:19130 <> 30008 / 30004 <> 192.168.2.106:33044 [SRTP]

All this looks fine. However, the final packet stats don't look so good. Both calls are terminated due to timeout:

Jul 24 15:19:09 localhost rtpengine[4945]: Closing call branch due to timeout
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] Final packet stats:
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] --- Tag 'f242e810', created 1:00 ago, in dialogue with 'a5bc7e554'
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] ------ Media #1, port 30002 <>   192.168.2.106:33042, 0 p, 0 b, 0 e
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] ------ Media #1, port 30003 <>   192.168.2.106:33043 (RTCP), 0 p, 0 b, 0 e
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] --- Tag 'a5bc7e554', created 1:00 ago, in dialogue with 'f242e810'
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] ------ Media #1, port 30000 <>      10.1.0.121:19110, 0 p, 0 b, 0 e
Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] ------ Media #1, port 30001 <>      10.1.0.121:19111 (RTCP), 0 p, 0 b, 0 e
Jul 24 15:19:54 localhost rtpengine[4945]: Closing call branch due to timeout
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] Final packet stats:
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] --- Tag 'cdbc926be2', created 1:00 ago, in dialogue with '422ab553'
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30008 <>            [::]:0    , 0 p, 0 b, 0 e
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30009 <>            [::]:0     (RTCP), 0 p, 0 b, 0 e
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] --- Tag 'ad508ba5ae', created 1:00 ago, in dialogue with '422ab553'
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30006 <>      10.1.0.121:19130, 0 p, 0 b, 0 e
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30007 <>      10.1.0.121:19131 (RTCP), 0 p, 0 b, 0 e
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] --- Tag '422ab553', created 1:00 ago, in dialogue with 'cdbc926be2'
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30004 <>   192.168.2.106:33044, 0 p, 0 b, 0 e
Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30005 <>   192.168.2.106:33045 (RTCP), 0 p, 0 b, 0 e

And all packet stats are zero. This means that rtpengine has never seen any packets coming in on any of these ports. My first guess would be an iptables packet filter. Otherwise perhaps an IP/routing configuration issue? Or possibly an overlap in UDP port ranges with something else that has the same ports open (unlikely).

edjames99 commented 10 years ago

Hi Richard,

      Thanks, it’s really useful to know that the rtpengine didn’t receive any of the packets. I’m now on holiday until 11th August but I’ll pick this up again then.

Thanks for your help.

Ed

From: Richard Fuchs [mailto:notifications@github.com] Sent: 25 July 2014 19:42 To: sipwise/rtpengine Cc: edjames99 Subject: Re: [rtpengine] No RTP/SRTP Sent (#12)

So we have...

First call, 2cb67bfe-5a85-4010-8e20-572bd9cd24f6

[SRTP] 192.168.2.106:33042 <> 30002 / 30000 <> 10.1.0.121:19110 [RTP]

IOW, packets received on port 30000 are sent out on port 30002 to side A, and packets received on port 30002 are sent out on port 30000 to side B.

Second call, YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU

[RTP] 10.1.0.121:19130 <> 30006 / 30004 <> 192.168.2.106:33488 [SRTP] then [RTP] 10.1.0.121:19130 <> 30008 / 30004 <> 192.168.2.106:33044 [SRTP]

All this looks fine. However, the final packet stats don't look so good. Both calls are terminated due to timeout:

Jul 24 15:19:09 localhost rtpengine[4945]: Closing call branch due to timeout Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] Final packet stats: Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] --- Tag 'f242e810', created 1:00 ago, in dialogue with 'a5bc7e554' Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] ------ Media #1, port 30002 <> 192.168.2.106:33042, 0 p, 0 b, 0 e Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] ------ Media #1, port 30003 <> 192.168.2.106:33043 (RTCP), 0 p, 0 b, 0 e Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] --- Tag 'a5bc7e554', created 1:00 ago, in dialogue with 'f242e810' Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] ------ Media #1, port 30000 <> 10.1.0.121:19110, 0 p, 0 b, 0 e Jul 24 15:19:09 localhost rtpengine[4945]: [2cb67bfe-5a85-4010-8e20-572bd9cd24f6] ------ Media #1, port 30001 <> 10.1.0.121:19111 (RTCP), 0 p, 0 b, 0 e Jul 24 15:19:54 localhost rtpengine[4945]: Closing call branch due to timeout Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] Final packet stats: Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] --- Tag 'cdbc926be2', created 1:00 ago, in dialogue with '422ab553' Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30008 <> [::]:0 , 0 p, 0 b, 0 e Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30009 <> [::]:0 (RTCP), 0 p, 0 b, 0 e Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] --- Tag 'ad508ba5ae', created 1:00 ago, in dialogue with '422ab553' Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30006 <> 10.1.0.121:19130, 0 p, 0 b, 0 e Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30007 <> 10.1.0.121:19131 (RTCP), 0 p, 0 b, 0 e Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] --- Tag '422ab553', created 1:00 ago, in dialogue with 'cdbc926be2' Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30004 <> 192.168.2.106:33044, 0 p, 0 b, 0 e Jul 24 15:19:54 localhost rtpengine[4945]: [YjFhY2Q5OTUzMGVmM2RkMDRkNDI1NzNkYzg0YTM3NzU.] ------ Media #1, port 30005 <> 192.168.2.106:33045 (RTCP), 0 p, 0 b, 0 e

And all packet stats are zero. This means that rtpengine has never seen any packets coming in on any of these ports. My first guess would be an iptables packet filter. Otherwise perhaps an IP/routing configuration issue? Or possibly an overlap in UDP port ranges with something else that has the same ports open (unlikely).

— Reply to this email directly or view it on GitHub https://github.com/sipwise/rtpengine/issues/12#issuecomment-50188234 . https://github.com/notifications/beacon/4895891__eyJzY29wZSI6Ik5ld3NpZXM6QmVhY29uIiwiZXhwaXJlcyI6MTcyMTkzMjkwMywiZGF0YSI6eyJpZCI6Mzc3NzgzMDV9fQ==--aa1230e84d6f506678a7f31653703d84c1e06409.gif

edjames99 commented 10 years ago

Hi Richard, Thanks very much for your help, this lack of packets was an ip tables issue which is now fixed. I'm now getting some new errors relating to the call leg which is outbound from RTPEngine, I believe the call leg inbound to RTPEngine is working fine. I've included the full log file below but I suspect that the errors are due to a failure to negotiate the crypto suite for the outbound leg and the only difference between the crypto attribute on the inbound sdp offer and the outbound sdp offer seems to be that the RTPEngine doesn't include the lifetime and the MKI in the crypto attribute in an outbound offer so:

Offer inbound to RTPEngine: a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:vv8e7tkaWbcILGtwJKXLVI+GlklTLAnI/A4E/HMk|2^31|1:1 a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:2nCSsIhNJaAc6ZH+r76Tk0RsdeVgpmcRr99fMB+W|2^31

Offer outbound from RTPEngine (no lifetime or MKI): a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:/UjhTmkmsnkeKJ4FJFQTgrJ/xeEsphDDYclGM

It's then saying later on in the logs that SRTP and SRTCP output required but there's no crypto suite agreed. Do you think this could be the cause ? If so where in the code can I make a change which will write these fields out into the message ? The __generate_crypto function already has a lifetime for SRTP and SRTCP (I made it use &crypto_suites[0] to make sure of this) but it doesn't come out in the message.

Thanks for your help Richard, it's much appreciated. The full log:

Aug 20 15:39:13 localhost rtpengine[16796]: Generating new DTLS certificate Aug 20 15:39:13 localhost rtpengine[16797]: Startup complete, version undefined Aug 20 15:39:20 localhost /usr/local/sbin/kamailio[16455]: NOTICE: Githubissues.

  • Githubissues is a development platform for aggregating issues.