WITH diff.chan_sip_devstate1.4debug APPLIED: ============================================ -- Registered SIP 'xlite' at 192.168.0.15 port 16218 expires 3600 [Nov 10 15:45:13] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:45:13] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE -- Registered SIP 'snom' at 192.168.0.15 port 5060 expires 120 [Nov 10 15:45:27] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:45:27] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:46:32] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: -- Executing [1235@default:1] Dial("SIP/xlite-088ef1f0", "SIP/snom") in new stack -- Called snom devicestate[xlite]=NOT_INUSE [Nov 10 15:46:32] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE -- SIP/snom-088ea970 is ringing [Nov 10 15:46:32] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:46:32] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE -- SIP/snom-088ea970 answered SIP/xlite-088ef1f0 [Nov 10 15:47:00] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:00] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:00] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:00] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:06] NOTICE[24181]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:7439 [Nov 10 15:47:08] DEBUG[24181]: channel.c:3679 ast_generic_bridge: Didn't get a frame from channel: SIP/snom-088ea970 [Nov 10 15:47:08] DEBUG[24181]: channel.c:3984 ast_channel_bridge: Bridge stops bridging channels SIP/xlite-088ef1f0 and SIP/snom-088ea970 == Spawn extension (default, 1235, 1) exited non-zero on 'SIP/xlite-088ef1f0' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"Jane Smith" <1234>' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1234' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1235' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'default' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/xlite-088ef1f0' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom-088ea970' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:46:32' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:47:00' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:47:08' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '36' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '8' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1163184392.0' [Nov 10 15:47:08] DEBUG[24181]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 15:47:08] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:09] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:09] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:09] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:19] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:19] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE -- Executing [1235@default:1] Dial("SIP/snom-088ef1f0", "SIP/snom") in new stack -- Called snom -- SIP/snom-088ea580 is ringing [Nov 10 15:47:19] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:19] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE -- SIP/snom-088ea580 answered SIP/snom-088ef1f0 -- Native bridging SIP/snom-088ef1f0 and SIP/snom-088ea580 [Nov 10 15:47:24] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:24] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:24] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:24] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:25] DEBUG[24208]: channel.c:3918 ast_channel_bridge: Returning from native bridge, channels: SIP/snom-088ef1f0, SIP/snom-088ea580 == Spawn extension (default, 1235, 1) exited non-zero on 'SIP/snom-088ef1f0' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"unknown" ' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'snom' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1235' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'default' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom-088ef1f0' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom-088ea580' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:47:19' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:47:24' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:47:25' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '6' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1163184439.2' [Nov 10 15:47:25] DEBUG[24208]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 15:47:25] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:25] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:25] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:25] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:27] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:27] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:29] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:29] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE -- Executing [1234@default:1] Dial("SIP/snom-088ea580", "SIP/xlite") in new stack -- Called xlite -- SIP/xlite-088f3e18 is ringing [Nov 10 15:47:29] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:29] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE -- SIP/xlite-088f3e18 answered SIP/snom-088ea580 [Nov 10 15:47:31] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:31] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:31] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:31] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:34] DEBUG[24216]: channel.c:3679 ast_generic_bridge: Didn't get a frame from channel: SIP/snom-088ea580 [Nov 10 15:47:34] DEBUG[24216]: channel.c:3984 ast_channel_bridge: Bridge stops bridging channels SIP/snom-088ea580 and SIP/xlite-088f3e18 == Spawn extension (default, 1234, 1) exited non-zero on 'SIP/snom-088ea580' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"unknown" ' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'snom' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1234' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'default' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom-088ea580' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/xlite-088f3e18' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/xlite' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:47:29' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:47:31' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:47:34' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '5' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '3' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1163184449.4' [Nov 10 15:47:34] DEBUG[24216]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 15:47:34] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:34] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:34] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:34] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:39] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:39] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE -- Executing [1234@default:1] Dial("SIP/snom-088ea580", "SIP/xlite") in new stack -- Called xlite -- SIP/xlite-088f3e18 is ringing [Nov 10 15:47:39] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:39] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE -- SIP/xlite-088f3e18 answered SIP/snom-088ea580 [Nov 10 15:47:40] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:40] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:40] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:40] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE -- Started music on hold, class 'default', on SIP/xlite-088f3e18 [Nov 10 15:47:43] DEBUG[24224]: channel.c:1908 ast_settimeout: Scheduling timer at 160 sample intervals [Nov 10 15:47:43] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:43] NOTICE[24139]: chan_sip.c:14898 sip_devicestate: devicestate[snom]=ONHOLD [Nov 10 15:47:43] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:43] NOTICE[24139]: chan_sip.c:14898 sip_devicestate: devicestate[snom]=ONHOLD [Nov 10 15:47:43] DEBUG[24224]: channel.c:1908 ast_settimeout: Scheduling timer at 0 sample intervals RTCP SR transmission error, rtcp halted [Nov 10 15:47:46] NOTICE[24158]: sched.c:283 ast_sched_del: Attempted to delete nonexistent schedule entry 84! [Nov 10 15:47:46] NOTICE[24224]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:31459 [Nov 10 15:47:49] NOTICE[24224]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:31459 -- Stopped music on hold on SIP/xlite-088f3e18 [Nov 10 15:47:52] DEBUG[24224]: channel.c:1908 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 10 15:47:52] NOTICE[24224]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:31459 [Nov 10 15:47:55] NOTICE[24224]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:31459 [Nov 10 15:47:58] DEBUG[24224]: channel.c:3679 ast_generic_bridge: Didn't get a frame from channel: SIP/snom-088ea580 [Nov 10 15:47:58] DEBUG[24224]: channel.c:3984 ast_channel_bridge: Bridge stops bridging channels SIP/snom-088ea580 and SIP/xlite-088f3e18 == Spawn extension (default, 1234, 1) exited non-zero on 'SIP/snom-088ea580' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"unknown" ' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'snom' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1234' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'default' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom-088ea580' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/xlite-088f3e18' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/xlite' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:47:39' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:47:40' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:47:58' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '19' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '18' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1163184459.6' [Nov 10 15:47:58] DEBUG[24224]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 15:47:58] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:58] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:47:58] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:58] NOTICE[24139]: chan_sip.c:14898 sip_devicestate: devicestate[snom]=ONHOLD [Nov 10 15:47:58] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:47:58] NOTICE[24139]: chan_sip.c:14898 sip_devicestate: devicestate[snom]=ONHOLD [Nov 10 15:48:10] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:48:10] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE -- Executing [1235@default:1] Dial("SIP/xlite-088ef1f0", "SIP/snom") in new stack -- Called snom -- SIP/snom-088ea580 is ringing [Nov 10 15:48:11] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:48:11] NOTICE[24139]: chan_sip.c:14898 sip_devicestate: devicestate[snom]=ONHOLD [Nov 10 15:48:11] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:48:11] NOTICE[24139]: chan_sip.c:14898 sip_devicestate: devicestate[snom]=ONHOLD -- SIP/snom-088ea580 answered SIP/xlite-088ef1f0 [Nov 10 15:48:13] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:48:13] NOTICE[24139]: chan_sip.c:14898 sip_devicestate: devicestate[snom]=ONHOLD [Nov 10 15:48:13] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:48:13] NOTICE[24139]: chan_sip.c:14898 sip_devicestate: devicestate[snom]=ONHOLD [Nov 10 15:48:13] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:48:13] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:48:16] DEBUG[24231]: channel.c:3679 ast_generic_bridge: Didn't get a frame from channel: SIP/snom-088ea580 [Nov 10 15:48:16] DEBUG[24231]: channel.c:3984 ast_channel_bridge: Bridge stops bridging channels SIP/xlite-088ef1f0 and SIP/snom-088ea580 == Spawn extension (default, 1235, 1) exited non-zero on 'SIP/xlite-088ef1f0' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"Jane Smith" <1234>' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1234' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1235' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'default' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/xlite-088ef1f0' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom-088ea580' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:48:10' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:48:13' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 15:48:16' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '6' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '3' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1163184490.8' [Nov 10 15:48:16] DEBUG[24231]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 15:48:16] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:48:16] NOTICE[24139]: chan_sip.c:14898 sip_devicestate: devicestate[snom]=ONHOLD [Nov 10 15:48:16] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[snom]=NOT_INUSE [Nov 10 15:48:16] NOTICE[24139]: chan_sip.c:14898 sip_devicestate: devicestate[snom]=ONHOLD [Nov 10 15:48:16] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE [Nov 10 15:48:16] NOTICE[24139]: chan_sip.c:14894 sip_devicestate: devicestate[xlite]=NOT_INUSE -- Unregistered SIP 'snom' [Nov 10 15:48:29] NOTICE[24139]: chan_sip.c:14912 sip_devicestate: devicestate[snom]=UNAVAILABLE [Nov 10 15:48:29] NOTICE[24139]: chan_sip.c:14912 sip_devicestate: devicestate[snom]=UNAVAILABLE -- Unregistered SIP 'xlite' [Nov 10 15:48:34] NOTICE[24139]: chan_sip.c:14912 sip_devicestate: devicestate[xlite]=UNAVAILABLE [Nov 10 15:48:34] NOTICE[24139]: chan_sip.c:14912 sip_devicestate: devicestate[xlite]=UNAVAILABLE WITH diff.chan_sip_devstate1.2debug APPLIED: ============================================ -- Registered SIP 'xlite' at 192.168.0.15 port 17104 expires 3600 [Nov 10 16:16:53] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:16:53] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:16:53] NOTICE[2666]: chan_sip.c:11839 handle_response_peerpoke: Peer 'xlite' is now Reachable. (7ms / 2000ms) [Nov 10 16:16:53] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:16:53] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) -- Registered SIP 'snom' at 192.168.0.15 port 5060 expires 120 [Nov 10 16:17:07] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:07] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:15] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) -- Executing [1235@default:1] Dial("SIP/xlite-09f6dbd0", "SIP/snom") in new stack -- Called snom [Nov 10 16:17:15] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) -- SIP/snom-09f72b58 is ringing [Nov 10 16:17:15] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:15] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) -- SIP/snom-09f72b58 answered SIP/xlite-09f6dbd0 [Nov 10 16:17:22] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:22] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:22] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:22] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:28] NOTICE[2701]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:60647 [Nov 10 16:17:32] DEBUG[2701]: channel.c:3679 ast_generic_bridge: Didn't get a frame from channel: SIP/snom-09f72b58 [Nov 10 16:17:32] DEBUG[2701]: channel.c:3984 ast_channel_bridge: Bridge stops bridging channels SIP/xlite-09f6dbd0 and SIP/snom-09f72b58 == Spawn extension (default, 1235, 1) exited non-zero on 'SIP/xlite-09f6dbd0' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"Jane Smith" <1234>' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1234' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1235' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'default' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/xlite-09f6dbd0' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom-09f72b58' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 16:17:15' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 16:17:22' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 16:17:32' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '17' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '10' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1163186235.0' [Nov 10 16:17:32] DEBUG[2701]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 16:17:32] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:32] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:32] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:32] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:38] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:38] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) -- Executing [1234@default:1] Dial("SIP/snom-09f6aa60", "SIP/xlite") in new stack -- Called xlite -- SIP/xlite-09f7a288 is ringing [Nov 10 16:17:39] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:39] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) -- SIP/xlite-09f7a288 answered SIP/snom-09f6aa60 [Nov 10 16:17:40] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:40] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:40] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:40] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:44] DEBUG[2736]: channel.c:3679 ast_generic_bridge: Didn't get a frame from channel: SIP/snom-09f6aa60 [Nov 10 16:17:44] DEBUG[2736]: channel.c:3984 ast_channel_bridge: Bridge stops bridging channels SIP/snom-09f6aa60 and SIP/xlite-09f7a288 == Spawn extension (default, 1234, 1) exited non-zero on 'SIP/snom-09f6aa60' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"unknown" ' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'snom' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1234' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'default' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom-09f6aa60' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/xlite-09f7a288' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/xlite' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 16:17:38' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 16:17:40' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 16:17:44' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '6' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '4' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1163186258.2' [Nov 10 16:17:44] DEBUG[2736]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 16:17:44] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:44] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:44] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:44] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:48] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:48] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) -- Executing [1235@default:1] Dial("SIP/xlite-09f6aa60", "SIP/snom") in new stack -- Called snom -- SIP/snom-09f674e8 is ringing [Nov 10 16:17:48] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:48] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) -- SIP/snom-09f674e8 answered SIP/xlite-09f6aa60 [Nov 10 16:17:49] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:49] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:17:49] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:49] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) -- Started music on hold, class 'default', on SIP/snom-09f674e8 [Nov 10 16:17:51] DEBUG[2743]: channel.c:1908 ast_settimeout: Scheduling timer at 160 sample intervals [Nov 10 16:17:51] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:51] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:51] DEBUG[2743]: channel.c:1908 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 10 16:17:55] NOTICE[2743]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 0.0.0.0:0 -- Stopped music on hold on SIP/snom-09f674e8 [Nov 10 16:17:59] DEBUG[2743]: channel.c:1908 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 10 16:17:59] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:17:59] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:18:01] NOTICE[2743]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:4531 [Nov 10 16:18:03] DEBUG[2743]: channel.c:3679 ast_generic_bridge: Didn't get a frame from channel: SIP/snom-09f674e8 [Nov 10 16:18:03] DEBUG[2743]: channel.c:3984 ast_channel_bridge: Bridge stops bridging channels SIP/xlite-09f6aa60 and SIP/snom-09f674e8 == Spawn extension (default, 1235, 1) exited non-zero on 'SIP/xlite-09f6aa60' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"Jane Smith" <1234>' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1234' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1235' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'default' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/xlite-09f6aa60' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom-09f674e8' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 16:17:48' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 16:17:49' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 16:18:03' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '15' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '14' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1163186268.4' [Nov 10 16:18:03] DEBUG[2743]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 16:18:03] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:18:03] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:18:03] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:18:03] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) -- Executing [1234@default:1] Dial("SIP/snom-09f6aa60", "SIP/xlite") in new stack [Nov 10 16:18:05] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:18:05] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) -- Called xlite -- SIP/xlite-09f674e8 is ringing [Nov 10 16:18:05] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:18:05] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) -- SIP/xlite-09f674e8 answered SIP/snom-09f6aa60 [Nov 10 16:18:07] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:18:07] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:18:07] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:18:07] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) -- Started music on hold, class 'default', on SIP/xlite-09f674e8 [Nov 10 16:18:08] DEBUG[2758]: channel.c:1908 ast_settimeout: Scheduling timer at 160 sample intervals [Nov 10 16:18:08] DEBUG[2758]: channel.c:1908 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 10 16:18:08] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:18:08] DEBUG[2644]: channel.c:943 channel_find_locked: Avoiding initial deadlock for channel '0x9f6c3f8' [Nov 10 16:18:08] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) RTCP SR transmission error, rtcp halted [Nov 10 16:18:12] NOTICE[2666]: sched.c:283 ast_sched_del: Attempted to delete nonexistent schedule entry 89! [Nov 10 16:18:13] NOTICE[2758]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:4963 -- Stopped music on hold on SIP/xlite-09f674e8 [Nov 10 16:18:14] DEBUG[2758]: channel.c:1908 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 10 16:18:15] NOTICE[2758]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:4963 -- Started music on hold, class 'default', on SIP/xlite-09f674e8 [Nov 10 16:18:18] DEBUG[2758]: channel.c:1908 ast_settimeout: Scheduling timer at 160 sample intervals [Nov 10 16:18:18] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:18:18] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:18:18] DEBUG[2758]: channel.c:1908 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 10 16:18:19] NOTICE[2758]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:4963 RTCP SR transmission error, rtcp halted [Nov 10 16:18:19] NOTICE[2666]: sched.c:283 ast_sched_del: Attempted to delete nonexistent schedule entry 92! [Nov 10 16:18:21] NOTICE[2758]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:4963 -- Stopped music on hold on SIP/xlite-09f674e8 [Nov 10 16:18:23] DEBUG[2758]: channel.c:1908 ast_settimeout: Scheduling timer at 0 sample intervals [Nov 10 16:18:25] NOTICE[2758]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:4963 [Nov 10 16:18:27] NOTICE[2758]: rtp.c:902 ast_rtcp_read: Unknown RTCP packet (pt=207) received from 192.168.0.15:4963 [Nov 10 16:18:28] DEBUG[2758]: channel.c:3679 ast_generic_bridge: Didn't get a frame from channel: SIP/snom-09f6aa60 [Nov 10 16:18:28] DEBUG[2758]: channel.c:3984 ast_channel_bridge: Bridge stops bridging channels SIP/snom-09f6aa60 and SIP/xlite-09f674e8 == Spawn extension (default, 1234, 1) exited non-zero on 'SIP/snom-09f6aa60' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '"unknown" ' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'snom' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1234' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'default' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/snom-09f6aa60' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/xlite-09f674e8' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'Dial' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'SIP/xlite' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 16:18:05' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 16:18:07' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '2006-11-10 16:18:28' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '23' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '21' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'ANSWERED' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is 'DOCUMENTATION' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '1163186285.6' [Nov 10 16:18:28] DEBUG[2758]: pbx.c:1621 pbx_substitute_variables_helper_full: Function result is '' [Nov 10 16:18:28] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:18:28] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[xlite] UNKNOWN (call_limit) [Nov 10 16:18:28] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit) [Nov 10 16:18:28] NOTICE[2644]: chan_sip.c:14892 sip_devicestate: devicestate[snom] UNKNOWN (call_limit)