matrix.org/static/jira/browse/BOTS-144

166 lines
30 KiB
Plaintext

---
summary: verto bridge often fails to set up calls with media timeouts
---
created: 2015-12-01 23:36:55.0
creator: matthew
description: |-
The logs when this happens look like this:
{code}
freeswitch@adc-prd-matrix-003> 2015-12-01 23:29:12.876482 [INFO] mod_verto.c:3896 83.166.68.11:47686 Client Connect.
2015-12-01 23:29:12.876482 [INFO] mod_verto.c:1903 83.166.68.11:47686 Starting client thread.
2015-12-01 23:29:12.916477 [INFO] mod_verto.c:1256 83.166.68.11:47686 re-connecting session 8ac62b1c-dd65-4ace-99c6-7d76da0076a0
2015-12-01 23:30:17.316474 [NOTICE] switch_channel.c:1089 New Channel verto.rtc/3501 [1d632687-4519-4991-9184-8dbb336be57c]
2015-12-01 23:30:17.316474 [INFO] mod_dialplan_xml.c:637 Processing @matthew:matrix.org <1008>->3501 in context default
2015-12-01 23:30:17.336459 [INFO] switch_core_media.c:6194 Activating Audio ICE
2015-12-01 23:30:17.336459 [NOTICE] switch_rtp.c:4213 Activating RTP audio ICE: Xgvt+6OSsyHD9WwH:ypl7MUgL717hssEl 83.166.68.175:53551
2015-12-01 23:30:17.336459 [INFO] switch_core_media.c:6237 Activating RTCP PORT 53551
2015-12-01 23:30:17.336459 [INFO] switch_core_media.c:6245 Skipping RTCP ICE (Same as RTP)
2015-12-01 23:30:17.336459 [INFO] switch_rtp.c:3251 Activate RTP/RTCP audio DTLS client
2015-12-01 23:30:17.336459 [INFO] switch_rtp.c:3380 Changing audio DTLS state from OFF to HANDSHAKE
2015-12-01 23:30:17.336459 [INFO] switch_core_media.c:6578 Activating Video ICE
2015-12-01 23:30:17.336459 [NOTICE] switch_rtp.c:4213 Activating RTP video ICE: Xgvt+6OSsyHD9WwH:IVKEL61VqUAz4Amt 81.138.8.249:55194
2015-12-01 23:30:17.336459 [INFO] switch_core_media.c:6616 Activating VIDEO RTCP PORT 55194 interval 2000 mux 1
2015-12-01 23:30:17.336459 [INFO] switch_core_media.c:6627 Skipping VIDEO RTCP ICE (Same as VIDEO RTP)
2015-12-01 23:30:17.336459 [INFO] switch_rtp.c:3251 Activate RTP/RTCP video DTLS client
2015-12-01 23:30:17.336459 [INFO] switch_rtp.c:3380 Changing video DTLS state from OFF to HANDSHAKE
2015-12-01 23:30:17.336459 [NOTICE] mod_dptools.c:1309 Channel [verto.rtc/3501] has been answered
2015-12-01 23:30:17.336459 [INFO] mod_conference.c:2970 using channel sound prefix: /usr/local/freeswitch/sounds/en/us/callie
2015-12-01 23:30:17.366600 [WARNING] switch_core_file.c:341 File has 1 channels, muxing to 2 channels will occur.
2015-12-01 23:30:17.366600 [INFO] conference_member.c:128 verto.rtc/3501 binding '0' to 'mute'
2015-12-01 23:30:17.366600 [INFO] switch_ivr_async.c:213 Digit parser mod_conference: Setting realm to 'conf'
2015-12-01 23:30:17.366600 [INFO] conference_member.c:128 verto.rtc/3501 binding '*' to 'deaf mute'
2015-12-01 23:30:17.366600 [INFO] conference_member.c:128 verto.rtc/3501 binding '9' to 'energy up'
2015-12-01 23:30:17.366600 [INFO] conference_member.c:128 verto.rtc/3501 binding '8' to 'energy equ'
2015-12-01 23:30:17.366600 [INFO] conference_member.c:128 verto.rtc/3501 binding '7' to 'energy dn'
2015-12-01 23:30:17.366600 [INFO] conference_member.c:128 verto.rtc/3501 binding '3' to 'vol talk up'
2015-12-01 23:30:17.366600 [INFO] conference_member.c:128 verto.rtc/3501 binding '2' to 'vol talk zero'
2015-12-01 23:30:17.366600 [INFO] conference_member.c:128 verto.rtc/3501 binding '1' to 'vol talk dn'
2015-12-01 23:30:17.366600 [INFO] conference_member.c:128 verto.rtc/3501 binding '6' to 'vol listen up'
2015-12-01 23:30:17.366600 [INFO] conference_member.c:128 verto.rtc/3501 binding '5' to 'vol listen zero'
2015-12-01 23:30:17.366600 [INFO] conference_member.c:128 verto.rtc/3501 binding '4' to 'vol listen dn'
2015-12-01 23:30:17.366600 [INFO] conference_member.c:128 verto.rtc/3501 binding '#' to 'hangup'
2015-12-01 23:30:20.106608 [WARNING] mod_local_stream.c:703 Unknown source stereo, trying 'default'
2015-12-01 23:30:20.106608 [WARNING] switch_core_file.c:341 File has 1 channels, muxing to 2 channels will occur.
2015-12-01 23:30:47.326599 [NOTICE] switch_core_media.c:2153 Hangup verto.rtc/3501 [CS_EXECUTE] [MEDIA_TIMEOUT]
2015-12-01 23:30:47.336599 [NOTICE] switch_core_session.c:1664 Session 1 (verto.rtc/3501) Ended
2015-12-01 23:30:47.336599 [NOTICE] switch_core_session.c:1668 Close Channel verto.rtc/3501 [CS_DESTROY]
{code}
{code}
vertoas@ldc-prd-matrix-003:~/.forever$ cat 2gFT.log
Loading config file /home/vertoas/matrix-org/matrix-appservice-verto/config/config.yaml
[wss://fs.matrix.org:8082/]: OPENED
[wss://fs.matrix.org:8082/]: SENDING {"jsonrpc":"2.0","method":"login","params":{"login":"1008@fs.matrix.org","passwd":"secret","sessid":"8ac62b1c-dd65-4ace-99c6-7d76da0076a0"},"id":1}
[wss://fs.matrix.org:8082/]: MESSAGE {"jsonrpc":"2.0","id":1,"result":{"message":"logged in","sessid":"8ac62b1c-dd65-4ace-99c6-7d76da0076a0"}}
Running bridge on port 3510
83.166.68.251 - - [01/Dec/2015:23:30:10 +0000] "PUT /transactions/8963?access_token=secret HTTP/1.1" 200 2 "-" "Synapse/0.11.1 (b=master,t=v0.11.1,2ca01ed,dirty)"
Member update: room=!zOmsiVucpWbRRDjSwe:matrix.org member=@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org -> invite
[-] POST https://matrix.org/_matrix/client/v2_alpha/register (AS) Body: {"auth":{},"username":"fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn"}
[gsx90li4r5wkw] Handling request
83.166.68.251 - - [01/Dec/2015:23:30:10 +0000] "PUT /transactions/8964?access_token=secret HTTP/1.1" 200 2 "-" "Synapse/0.11.1 (b=master,t=v0.11.1,2ca01ed,dirty)"
[-] POST https://matrix.org/_matrix/client/v2_alpha/register (AS) HTTP 400 Error: {"errcode":"M_USER_IN_USE","error":"User ID already taken."}
[-] POST https://matrix.org/_matrix/client/api/v1/join/!zOmsiVucpWbRRDjSwe%3Amatrix.org (@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org) Body: {}
DELAYED: gsx90li4r5wkw
DELAYED: imhncoxnh5w0w
83.166.68.251 - - [01/Dec/2015:23:30:16 +0000] "PUT /transactions/8965?access_token=secret HTTP/1.1" 200 2 "-" "Synapse/0.11.1 (b=master,t=v0.11.1,2ca01ed,dirty)"
[-] POST https://matrix.org/_matrix/client/api/v1/join/!zOmsiVucpWbRRDjSwe%3Amatrix.org (@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org) HTTP 200 {"room_id":"!zOmsiVucpWbRRDjSwe:matrix.org"}
[gsx90li4r5wkw] SUCCESS (6087ms) 1
Call invite: room=!mBlOZJtrsMbppKbdXc:matrix.org member=@matthew:matrix.org content={"call_id":"c1449012610200","lifetime":60000,"offer":{"sdp":"v=0\r\no=- 6819588452651679356 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE audio video\r\na=msid-semantic: WMS JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD\r\nm=audio 59717 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126\r\nc=IN IP4 10.10.79.14\r\na=rtcp:62953 IN IP4 10.10.79.14\r\na=candidate:2484308238 1 udp 2122260223 10.10.79.14 59717 typ host generation 0\r\na=candidate:3376904655 1 udp 2122194687 192.168.1.144 53178 typ host generation 0\r\na=candidate:2484308238 2 udp 2122260222 10.10.79.14 62953 typ host generation 0\r\na=candidate:3376904655 2 udp 2122194686 192.168.1.144 50167 typ host generation 0\r\na=ice-ufrag:Xgvt+6OSsyHD9WwH\r\na=ice-pwd:zOjt3pjnjwxKQXPv7GNAwlSk\r\na=fingerprint:sha-256 1E:CD:33:C0:F2:C6:F9:2C:1B:79:C5:2C:B6:F9:3E:C9:00:70:15:2E:7D:CF:4D:78:CF:F1:29:FA:7F:FD:44:02\r\na=setup:actpass\r\na=mid:audio\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=sendrecv\r\na=rtcp-mux\r\na=rtpmap:111 opus/48000/2\r\na=fmtp:111 minptime=10; useinbandfec=1\r\na=rtpmap:103 ISAC/16000\r\na=rtpmap:104 ISAC/32000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:106 CN/32000\r\na=rtpmap:105 CN/16000\r\na=rtpmap:13 CN/8000\r\na=rtpmap:126 telephone-event/8000\r\na=maxptime:60\r\na=ssrc:4254207936 cname:QJCevg61DMsxok0i\r\na=ssrc:4254207936 msid:JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD 4fe5963c-5767-4fe8-8ffc-c8864e8a5603\r\na=ssrc:4254207936 mslabel:JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD\r\na=ssrc:4254207936 label:4fe5963c-5767-4fe8-8ffc-c8864e8a5603\r\nm=video 63406 UDP/TLS/RTP/SAVPF 100 116 117 96\r\nc=IN IP4 10.10.79.14\r\na=rtcp:52773 IN IP4 10.10.79.14\r\na=candidate:2484308238 1 udp 2122260223 10.10.79.14 63406 typ host generation 0\r\na=candidate:3376904655 1 udp 2122194687 192.168.1.144 55194 typ host generation 0\r\na=candidate:2484308238 2 udp 2122260222 10.10.79.14 52773 typ host generation 0\r\na=candidate:3376904655 2 udp 2122194686 192.168.1.144 50467 typ host generation 0\r\na=ice-ufrag:Xgvt+6OSsyHD9WwH\r\na=ice-pwd:zOjt3pjnjwxKQXPv7GNAwlSk\r\na=fingerprint:sha-256 1E:CD:33:C0:F2:C6:F9:2C:1B:79:C5:2C:B6:F9:3E:C9:00:70:15:2E:7D:CF:4D:78:CF:F1:29:FA:7F:FD:44:02\r\na=setup:actpass\r\na=mid:video\r\na=extmap:2 urn:ietf:params:rtp-hdrext:toffset\r\na=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=extmap:4 urn:3gpp:video-orientation\r\na=sendrecv\r\na=rtcp-mux\r\na=rtpmap:100 VP8/90000\r\na=rtcp-fb:100 ccm fir\r\na=rtcp-fb:100 nack\r\na=rtcp-fb:100 nack pli\r\na=rtcp-fb:100 goog-remb\r\na=rtpmap:116 red/90000\r\na=rtpmap:117 ulpfec/90000\r\na=rtpmap:96 rtx/90000\r\na=fmtp:96 apt=100\r\na=ssrc-group:FID 3974403577 522615485\r\na=ssrc:3974403577 cname:QJCevg61DMsxok0i\r\na=ssrc:3974403577 msid:JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD 2a4a2115-51bd-4714-9610-f1d44dc1813b\r\na=ssrc:3974403577 mslabel:JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD\r\na=ssrc:3974403577 label:2a4a2115-51bd-4714-9610-f1d44dc1813b\r\na=ssrc:522615485 cname:QJCevg61DMsxok0i\r\na=ssrc:522615485 msid:JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD 2a4a2115-51bd-4714-9610-f1d44dc1813b\r\na=ssrc:522615485 mslabel:JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD\r\na=ssrc:522615485 label:2a4a2115-51bd-4714-9610-f1d44dc1813b\r\n","type":"offer"},"version":0}
[imhncoxnh5w0w] Handling request
[-] GET https://matrix.org/_matrix/client/api/v1/rooms/!zOmsiVucpWbRRDjSwe%3Amatrix.org/state (@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org) Body:
[-] GET https://matrix.org/_matrix/client/api/v1/rooms/!zOmsiVucpWbRRDjSwe%3Amatrix.org/state (@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org) HTTP 200 [{"origin_server_ts":1429032518196,"user_id":"@kegan:matrix.org","event_id":"$14
Init verto call for fs_user @fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org
Add matrix side for fs_user @fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org (@matthew:matrix.org)
Storing verto call on ext=3501 fs_user=@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org matrix_users=1
[imhncoxnh5w0w] SUCCESS (6708ms) undefined
Call candidates: room=!mBlOZJtrsMbppKbdXc:matrix.org member=@matthew:matrix.org content={"call_id":"c1449012610200","candidates":[{"candidate":"candidate:2484308238 1 udp 2122260223 10.10.79.14 59717 typ host generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:3376904655 1 udp 2122194687 192.168.1.144 53178 typ host generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:2484308238 2 udp 2122260222 10.10.79.14 62953 typ host generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:3376904655 2 udp 2122194686 192.168.1.144 50167 typ host generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:2484308238 1 udp 2122260223 10.10.79.14 63406 typ host generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:3376904655 1 udp 2122194687 192.168.1.144 55194 typ host generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:2484308238 2 udp 2122260222 10.10.79.14 52773 typ host generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:3376904655 2 udp 2122194686 192.168.1.144 50467 typ host generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:1208975227 1 udp 1685987071 81.138.8.249 53178 typ srflx raddr 192.168.1.144 rport 53178 generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:1208975227 2 udp 1685987070 81.138.8.249 50167 typ srflx raddr 192.168.1.144 rport 50167 generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:1208975227 1 udp 1685987071 81.138.8.249 55194 typ srflx raddr 192.168.1.144 rport 55194 generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:1208975227 2 udp 1685987070 81.138.8.249 50467 typ srflx raddr 192.168.1.144 rport 50467 generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:3666900478 1 tcp 1518280447 10.10.79.14 0 typ host tcptype active generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:2277803327 1 tcp 1518214911 192.168.1.144 0 typ host tcptype active generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:3666900478 2 tcp 1518280446 10.10.79.14 0 typ host tcptype active generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:2277803327 2 tcp 1518214910 192.168.1.144 0 typ host tcptype active generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:3666900478 1 tcp 1518280447 10.10.79.14 0 typ host tcptype active generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:2277803327 1 tcp 1518214911 192.168.1.144 0 typ host tcptype active generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:3666900478 2 tcp 1518280446 10.10.79.14 0 typ host tcptype active generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:2277803327 2 tcp 1518214910 192.168.1.144 0 typ host tcptype active generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:1782478627 1 udp 41819903 83.166.68.175 53551 typ relay raddr 81.138.8.249 rport 53178 generation 0","sdpMLineIndex":0,"sdpMid":"audio"}],"version":0}
Gathered enough candidates for c1449012610200
index=0 - m=audio 59717 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126
Inserted candidate candidate:2484308238 1 udp 2122260223 10.10.79.14 59717 typ host generation 0 at m= index 0
Inserted candidate candidate:3376904655 1 udp 2122194687 192.168.1.144 53178 typ host generation 0 at m= index 0
Inserted candidate candidate:2484308238 2 udp 2122260222 10.10.79.14 62953 typ host generation 0 at m= index 0
Inserted candidate candidate:3376904655 2 udp 2122194686 192.168.1.144 50167 typ host generation 0 at m= index 0
Inserted candidate candidate:1208975227 1 udp 1685987071 81.138.8.249 53178 typ srflx raddr 192.168.1.144 rport 53178 generation 0 at m= index 0
Inserted candidate candidate:1208975227 2 udp 1685987070 81.138.8.249 50167 typ srflx raddr 192.168.1.144 rport 50167 generation 0 at m= index 0
Inserted candidate candidate:3666900478 1 tcp 1518280447 10.10.79.14 0 typ host tcptype active generation 0 at m= index 0
Inserted candidate candidate:2277803327 1 tcp 1518214911 192.168.1.144 0 typ host tcptype active generation 0 at m= index 0
Inserted candidate candidate:3666900478 2 tcp 1518280446 10.10.79.14 0 typ host tcptype active generation 0 at m= index 0
Inserted candidate candidate:2277803327 2 tcp 1518214910 192.168.1.144 0 typ host tcptype active generation 0 at m= index 0
Inserted candidate candidate:1782478627 1 udp 41819903 83.166.68.175 53551 typ relay raddr 81.138.8.249 rport 53178 generation 0 at m= index 0
index=1 - m=video 63406 UDP/TLS/RTP/SAVPF 100 116 117 96
Inserted candidate candidate:2484308238 1 udp 2122260223 10.10.79.14 63406 typ host generation 0 at m= index 1
Inserted candidate candidate:3376904655 1 udp 2122194687 192.168.1.144 55194 typ host generation 0 at m= index 1
Inserted candidate candidate:2484308238 2 udp 2122260222 10.10.79.14 52773 typ host generation 0 at m= index 1
Inserted candidate candidate:3376904655 2 udp 2122194686 192.168.1.144 50467 typ host generation 0 at m= index 1
Inserted candidate candidate:1208975227 1 udp 1685987071 81.138.8.249 55194 typ srflx raddr 192.168.1.144 rport 55194 generation 0 at m= index 1
Inserted candidate candidate:1208975227 2 udp 1685987070 81.138.8.249 50467 typ srflx raddr 192.168.1.144 rport 50467 generation 0 at m= index 1
Inserted candidate candidate:3666900478 1 tcp 1518280447 10.10.79.14 0 typ host tcptype active generation 0 at m= index 1
Inserted candidate candidate:2277803327 1 tcp 1518214911 192.168.1.144 0 typ host tcptype active generation 0 at m= index 1
Inserted candidate candidate:3666900478 2 tcp 1518280446 10.10.79.14 0 typ host tcptype active generation 0 at m= index 1
Inserted candidate candidate:2277803327 2 tcp 1518214910 192.168.1.144 0 typ host tcptype active generation 0 at m= index 1
[wss://fs.matrix.org:8082/]: SENDING {"jsonrpc":"2.0","method":"verto.invite","params":{"sdp":"v=0\r\no=- 6819588452651679356 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE audio video\r\na=msid-semantic: WMS JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD\r\nm=audio 59717 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126\r\nc=IN IP4 10.10.79.14\r\na=candidate:1782478627 1 udp 41819903 83.166.68.175 53551 typ relay raddr 81.138.8.249 rport 53178 generation 0\r\na=candidate:2277803327 2 tcp 1518214910 192.168.1.144 0 typ host tcptype active generation 0\r\na=candidate:3666900478 2 tcp 1518280446 10.10.79.14 0 typ host tcptype active generation 0\r\na=candidate:2277803327 1 tcp 1518214911 192.168.1.144 0 typ host tcptype active generation 0\r\na=candidate:3666900478 1 tcp 1518280447 10.10.79.14 0 typ host tcptype active generation 0\r\na=candidate:1208975227 2 udp 1685987070 81.138.8.249 50167 typ srflx raddr 192.168.1.144 rport 50167 generation 0\r\na=candidate:1208975227 1 udp 1685987071 81.138.8.249 53178 typ srflx raddr 192.168.1.144 rport 53178 generation 0\r\na=candidate:3376904655 2 udp 2122194686 192.168.1.144 50167 typ host generation 0\r\na=candidate:2484308238 2 udp 2122260222 10.10.79.14 62953 typ host generation 0\r\na=candidate:3376904655 1 udp 2122194687 192.168.1.144 53178 typ host generation 0\r\na=candidate:2484308238 1 udp 2122260223 10.10.79.14 59717 typ host generation 0\r\na=rtcp:62953 IN IP4 10.10.79.14\r\na=candidate:2484308238 1 udp 2122260223 10.10.79.14 59717 typ host generation 0\r\na=candidate:3376904655 1 udp 2122194687 192.168.1.144 53178 typ host generation 0\r\na=candidate:2484308238 2 udp 2122260222 10.10.79.14 62953 typ host generation 0\r\na=candidate:3376904655 2 udp 2122194686 192.168.1.144 50167 typ host generation 0\r\na=ice-ufrag:Xgvt+6OSsyHD9WwH\r\na=ice-pwd:zOjt3pjnjwxKQXPv7GNAwlSk\r\na=fingerprint:sha-256 1E:CD:33:C0:F2:C6:F9:2C:1B:79:C5:2C:B6:F9:3E:C9:00:70:15:2E:7D:CF:4D:78:CF:F1:29:FA:7F:FD:44:02\r\na=setup:actpass\r\na=mid:audio\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=sendrecv\r\na=rtcp-mux\r\na=rtpmap:111 opus/48000/2\r\na=fmtp:111 minptime=10; useinbandfec=1\r\na=rtpmap:103 ISAC/16000\r\na=rtpmap:104 ISAC/32000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:106 CN/32000\r\na=rtpmap:105 CN/16000\r\na=rtpmap:13 CN/8000\r\na=rtpmap:126 telephone-event/8000\r\na=maxptime:60\r\na=ssrc:4254207936 cname:QJCevg61DMsxok0i\r\na=ssrc:4254207936 msid:JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD 4fe5963c-5767-4fe8-8ffc-c8864e8a5603\r\na=ssrc:4254207936 mslabel:JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD\r\na=ssrc:4254207936 label:4fe5963c-5767-4fe8-8ffc-c8864e8a5603\r\nm=video 63406 UDP/TLS/RTP/SAVPF 100 116 117 96\r\nc=IN IP4 10.10.79.14\r\na=candidate:2277803327 2 tcp 1518214910 192.168.1.144 0 typ host tcptype active generation 0\r\na=candidate:3666900478 2 tcp 1518280446 10.10.79.14 0 typ host tcptype active generation 0\r\na=candidate:2277803327 1 tcp 1518214911 192.168.1.144 0 typ host tcptype active generation 0\r\na=candidate:3666900478 1 tcp 1518280447 10.10.79.14 0 typ host tcptype active generation 0\r\na=candidate:1208975227 2 udp 1685987070 81.138.8.249 50467 typ srflx raddr 192.168.1.144 rport 50467 generation 0\r\na=candidate:1208975227 1 udp 1685987071 81.138.8.249 55194 typ srflx raddr 192.168.1.144 rport 55194 generation 0\r\na=candidate:3376904655 2 udp 2122194686 192.168.1.144 50467 typ host generation 0\r\na=candidate:2484308238 2 udp 2122260222 10.10.79.14 52773 typ host generation 0\r\na=candidate:3376904655 1 udp 2122194687 192.168.1.144 55194 typ host generation 0\r\na=candidate:2484308238 1 udp 2122260223 10.10.79.14 63406 typ host generation 0\r\na=rtcp:52773 IN IP4 10.10.79.14\r\na=candidate:2484308238 1 udp 2122260223 10.10.79.14 63406 typ host generation 0\r\na=candidate:3376904655 1 udp 2122194687 192.168.1.144 55194 typ host generation 0\r\na=candidate:2484308238 2 udp 2122260222 10.10.79.14 52773 typ host generation 0\r\na=candidate:3376904655 2 udp 2122194686 192.168.1.144 50467 typ host generation 0\r\na=ice-ufrag:Xgvt+6OSsyHD9WwH\r\na=ice-pwd:zOjt3pjnjwxKQXPv7GNAwlSk\r\na=fingerprint:sha-256 1E:CD:33:C0:F2:C6:F9:2C:1B:79:C5:2C:B6:F9:3E:C9:00:70:15:2E:7D:CF:4D:78:CF:F1:29:FA:7F:FD:44:02\r\na=setup:actpass\r\na=mid:video\r\na=extmap:2 urn:ietf:params:rtp-hdrext:toffset\r\na=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=extmap:4 urn:3gpp:video-orientation\r\na=sendrecv\r\na=rtcp-mux\r\na=rtpmap:100 VP8/90000\r\na=rtcp-fb:100 ccm fir\r\na=rtcp-fb:100 nack\r\na=rtcp-fb:100 nack pli\r\na=rtcp-fb:100 goog-remb\r\na=rtpmap:116 red/90000\r\na=rtpmap:117 ulpfec/90000\r\na=rtpmap:96 rtx/90000\r\na=fmtp:96 apt=100\r\na=ssrc-group:FID 3974403577 522615485\r\na=ssrc:3974403577 cname:QJCevg61DMsxok0i\r\na=ssrc:3974403577 msid:JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD 2a4a2115-51bd-4714-9610-f1d44dc1813b\r\na=ssrc:3974403577 mslabel:JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD\r\na=ssrc:3974403577 label:2a4a2115-51bd-4714-9610-f1d44dc1813b\r\na=ssrc:522615485 cname:QJCevg61DMsxok0i\r\na=ssrc:522615485 msid:JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD 2a4a2115-51bd-4714-9610-f1d44dc1813b\r\na=ssrc:522615485 mslabel:JlCFeBUjnHcaTPhmwiMD9IUDiVXggLDNWOfD\r\na=ssrc:522615485 label:2a4a2115-51bd-4714-9610-f1d44dc1813b\r\n","dialogParams":{"useVideo":true,"useStereo":true,"useSpeak":"any","screenShare":false,"useCamera":"any","useMic":"any","tag":"webcam","localTag":null,"login":"1008@fs.matrix.org","caller_id_number":"1008","outgoingBandwidth":"default","incomingBandwidth":"default","dedEnc":false,"mirrorInput":false,"remote_caller_id_name":"Outbound Call","userVariables":{"avatar":"","email":""},"videoParams":{"maxHeight":240,"maxWidth":320,"minFrameRate":15,"minHeight":240,"minWidth":320},"callID":"1d632687-4519-4991-9184-8dbb336be57c","destination_number":"3501","remote_caller_id_number":"3501","caller_id_name":"@matthew:matrix.org"},"sessid":"8ac62b1c-dd65-4ace-99c6-7d76da0076a0"},"id":2}
[174bgy2rirogo] Handling request
[wss://fs.matrix.org:8082/]: MESSAGE {"jsonrpc":"2.0","id":2,"result":{"message":"CALL CREATED","callID":"1d632687-4519-4991-9184-8dbb336be57c","sessid":"8ac62b1c-dd65-4ace-99c6-7d76da0076a0"}}
[174bgy2rirogo] SUCCESS (1296ms) [ undefined,
{ message: 'CALL CREATED',
callID: '1d632687-4519-4991-9184-8dbb336be57c',
sessid: '8ac62b1c-dd65-4ace-99c6-7d76da0076a0' } ]
[wss://fs.matrix.org:8082/]: MESSAGE {"jsonrpc":"2.0","id":1,"method":"verto.answer","params":{"callID":"1d632687-4519-4991-9184-8dbb336be57c","sdp":"v=0\no=FreeSWITCH 1448980025 1448980026 IN IP4 83.166.69.14\ns=FreeSWITCH\nc=IN IP4 83.166.69.14\nt=0 0\na=msid-semantic: WMS mBhiE2S4XqMp7OaMx8knJwJj9nUwkBvw\nm=audio 32592 UDP/TLS/RTP/SAVPF 111 126\na=rtpmap:111 opus/48000/2\na=fmtp:111 useinbandfec=0; usedtx=1; minptime=10\na=rtpmap:126 telephone-event/8000\na=silenceSupp:off - - - -\na=ptime:20\na=sendrecv\na=fingerprint:sha-256 5A:77:2F:EA:AC:BD:15:11:2F:2A:49:E0:28:7B:E3:AD:B8:11:76:B1:A1:C0:99:01:6E:62:42:92:33:1C:F5:46\na=setup:active\na=rtcp-mux\na=rtcp:32592 IN IP4 83.166.69.14\na=ice-ufrag:ypl7MUgL717hssEl\na=ice-pwd:V9Jhn1qSXOkwepuCFFzhqGSn\na=candidate:9826540848 1 udp 659136 83.166.69.14 32592 typ host generation 0\na=ssrc:1466768009 cname:3CFxvnsiE5yCJze7\na=ssrc:1466768009 msid:mBhiE2S4XqMp7OaMx8knJwJj9nUwkBvw a0\na=ssrc:1466768009 mslabel:mBhiE2S4XqMp7OaMx8knJwJj9nUwkBvw\na=ssrc:1466768009 label:mBhiE2S4XqMp7OaMx8knJwJj9nUwkBvwa0\nm=video 26158 UDP/TLS/RTP/SAVPF 100\na=rtpmap:100 VP8/90000\na=fingerprint:sha-256 5A:77:2F:EA:AC:BD:15:11:2F:2A:49:E0:28:7B:E3:AD:B8:11:76:B1:A1:C0:99:01:6E:62:42:92:33:1C:F5:46\na=setup:active\na=rtcp-mux\na=rtcp:26158 IN IP4 83.166.69.14\nb=AS:1024\na=rtcp-fb:100 ccm fir\na=rtcp-fb:100 nack\na=rtcp-fb:100 nack pli\na=ssrc:742282572 cname:3CFxvnsiE5yCJze7\na=ssrc:742282572 msid:mBhiE2S4XqMp7OaMx8knJwJj9nUwkBvw v0\na=ssrc:742282572 mslabel:mBhiE2S4XqMp7OaMx8knJwJj9nUwkBvw\na=ssrc:742282572 label:mBhiE2S4XqMp7OaMx8knJwJj9nUwkBvwv0\na=ice-ufrag:IVKEL61VqUAz4Amt\na=ice-pwd:07bpbJTTmvq5XZEwLe1mbS7r\na=candidate:2289568236 1 udp 659136 83.166.69.14 26158 typ host generation 0\n"}}
[wss://fs.matrix.org:8082/]: MESSAGE {"jsonrpc":"2.0","id":2,"method":"verto.event","params":{"pvtData":{"action":"conference-liveArray-join","laChannel":"conference-liveArray.3501-83.166.69.14@83.166.69.14","laName":"3501-83.166.69.14","role":"participant","chatID":"conf+3501-83.166.69.14@83.166.69.14","canvasCount":1,"chatChannel":"conference-chat.3501-83.166.69.14@83.166.69.14"},"eventChannel":"8ac62b1c-dd65-4ace-99c6-7d76da0076a0","eventType":"channelPvtData"}}
83.166.68.251 - - [01/Dec/2015:23:30:17 +0000] "PUT /transactions/8966?access_token=secret HTTP/1.1" 200 2 "-" "Synapse/0.11.1 (b=master,t=v0.11.1,2ca01ed,dirty)"
Call candidates: room=!mBlOZJtrsMbppKbdXc:matrix.org member=@matthew:matrix.org content={"call_id":"c1449012610200","candidates":[{"candidate":"candidate:1782478627 2 udp 41819902 83.166.68.175 52922 typ relay raddr 81.138.8.249 rport 50167 generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:1782478627 2 udp 41819902 83.166.68.175 50457 typ relay raddr 81.138.8.249 rport 50467 generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:1782478627 1 udp 41819903 83.166.68.175 63001 typ relay raddr 81.138.8.249 rport 55194 generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:1782478627 2 udp 25042686 83.166.68.175 64848 typ relay raddr 81.138.8.249 rport 60788 generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:1782478627 1 udp 25042687 83.166.68.175 57502 typ relay raddr 81.138.8.249 rport 60784 generation 0","sdpMLineIndex":0,"sdpMid":"audio"},{"candidate":"candidate:1782478627 1 udp 25042687 83.166.68.175 53009 typ relay raddr 81.138.8.249 rport 60792 generation 0","sdpMLineIndex":1,"sdpMid":"video"},{"candidate":"candidate:1782478627 2 udp 25042686 83.166.68.175 59432 typ relay raddr 81.138.8.249 rport 60796 generation 0","sdpMLineIndex":1,"sdpMid":"video"}],"version":0}
Gathered enough candidates for c1449012610200
[4c0q6kguf8e8w] Handling request
[4c0q6kguf8e8w] SUCCESS (7ms) 'Invite already sent'
83.166.68.251 - - [01/Dec/2015:23:30:18 +0000] "PUT /transactions/8967?access_token=secret HTTP/1.1" 200 2 "-" "Synapse/0.11.1 (b=master,t=v0.11.1,2ca01ed,dirty)"
83.166.68.251 - - [01/Dec/2015:23:30:39 +0000] "PUT /transactions/8968?access_token=secret HTTP/1.1" 200 2 "-" "Synapse/0.11.1 (b=master,t=v0.11.1,2ca01ed,dirty)"
[gr9lo6xrr9wsc] SUCCESS (6ms) 'unhandled event'
[wss://fs.matrix.org:8082/]: MESSAGE {"jsonrpc":"2.0","id":3,"method":"verto.event","params":{"pvtData":{"action":"conference-liveArray-part","laChannel":"conference-liveArray.3501-83.166.69.14@83.166.69.14","laName":"3501-83.166.69.14","role":"participant","chatID":"conf+3501-83.166.69.14@83.166.69.14","canvasCount":1,"chatChannel":"conference-chat.3501-83.166.69.14@83.166.69.14"},"eventChannel":"8ac62b1c-dd65-4ace-99c6-7d76da0076a0","eventType":"channelPvtData"}}
Unhandled method: verto.event
[wss://fs.matrix.org:8082/]: MESSAGE {"jsonrpc":"2.0","id":4,"method":"verto.bye","params":{"callID":"1d632687-4519-4991-9184-8dbb336be57c","causeCode":604,"cause":"MEDIA_TIMEOUT"}}
Removed matrix side for fs_user @fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org (@matthew:matrix.org)
Deleting conf call for fs_user @fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org
[-] POST https://matrix.org/_matrix/client/api/v1/rooms/!zOmsiVucpWbRRDjSwe%3Amatrix.org/leave (@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org) Body: {}
[-] POST https://matrix.org/_matrix/client/api/v1/join/!mBlOZJtrsMbppKbdXc%3Amatrix.org (@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org) Body: {}
[-] POST https://matrix.org/_matrix/client/api/v1/rooms/!zOmsiVucpWbRRDjSwe%3Amatrix.org/leave (@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org) HTTP 200 {}
[-] POST https://matrix.org/_matrix/client/api/v1/join/!mBlOZJtrsMbppKbdXc%3Amatrix.org (@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org) HTTP 200 {"room_id":"!mBlOZJtrsMbppKbdXc:matrix.org"}
[-] GET https://matrix.org/_matrix/client/api/v1/rooms/!mBlOZJtrsMbppKbdXc%3Amatrix.org/state/m.room.power_levels/ (@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org) Body:
83.166.68.251 - - [01/Dec/2015:23:30:48 +0000] "PUT /transactions/8969?access_token=secret HTTP/1.1" 200 2 "-" "Synapse/0.11.1 (b=master,t=v0.11.1,2ca01ed,dirty)"
[-] GET https://matrix.org/_matrix/client/api/v1/rooms/!mBlOZJtrsMbppKbdXc%3Amatrix.org/state/m.room.power_levels/ (@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org) HTTP 200 {"events_default":0,"invite":0,"state_default":50,"redact":50,"ban":50,"users_de
[-] PUT https://matrix.org/_matrix/client/api/v1/rooms/!mBlOZJtrsMbppKbdXc%3Amatrix.org/send/m.call.hangup/m1449012648578 (@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org) Body: {"call_id":"c1449012610200","version":0}
83.166.68.251 - - [01/Dec/2015:23:30:48 +0000] "PUT /transactions/8970?access_token=secret HTTP/1.1" 200 2 "-" "Synapse/0.11.1 (b=master,t=v0.11.1,2ca01ed,dirty)"
[-] PUT https://matrix.org/_matrix/client/api/v1/rooms/!mBlOZJtrsMbppKbdXc%3Amatrix.org/send/m.call.hangup/m1449012648578 (@fs_IXpPbXNpVnVjcFdiUlJEalN3ZTptYXRyaXgub3Jn:matrix.org) HTTP 200 {"event_id":"$1449012648310233AbzWl:matrix.org"}
83.166.68.251 - - [01/Dec/2015:23:30:48 +0000] "PUT /transactions/8971?access_token=secret HTTP/1.1" 200 2 "-" "Synapse/0.11.1 (b=master,t=v0.11.1,2ca01ed,dirty)"
{code}
id: '12164'
key: BOTS-144
number: '144'
priority: '1'
project: '10101'
reporter: matthew
status: '1'
type: '1'
updated: 2015-12-01 23:37:59.0
votes: '0'
watches: '1'
workflowId: '12267'
---
actions: null