[Dec 20 10:45:34] DEBUG[2988960688]: Device 'SIP/3013' changed to state '1' (Not in use)
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Stopping retransmission on '69e0555459bcd5976e4c839c38728489@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Stopping retransmission on '363ddd6931efb6225d094eca24932c93@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Stopping retransmission on '6ab788de59530b224c85c7c61c9db4b0@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2988960688]: Device 'SIP/sipura02' changed to state '1' (Not in use)
[Dec 20 10:45:34] DEBUG[2987629488]: Stopping retransmission on '27bd77cf59ad2df136b67cbc5b49a94f@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Stopping retransmission on '5d36e06f2bc384a563e5eb336af25b13@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Stopping retransmission on '2c31e23b306def87231e77b9576f333c@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:45:34] DEBUG[2987629488]: Stopping retransmission on '39ce7ef82090487602d4fd167ea25d8f@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:35] DEBUG[2988960688]: Device 'SIP/sipura03' changed to state '1' (Not in use)
[Dec 20 10:45:35] DEBUG[2987629488]: Stopping retransmission on '6e9a83521657fb217005291226bba5ce@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:35] DEBUG[2987629488]: Stopping retransmission on '5b0e5d85396419136d8c0a4051872887@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:35] DEBUG[2987629488]: Stopping retransmission on '7bcd607958230a1d594c28fd71b7809e@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:35] DEBUG[2988960688]: Device 'SIP/sipura01' changed to state '1' (Not in use)
[Dec 20 10:45:35] DEBUG[2988960688]: Device 'SIP/3014' changed to state '1' (Not in use)
[Dec 20 10:45:35] VERBOSE[2988428208]: [Dec 20 10:45:34] OpenPBX Ready.
[Dec 20 10:45:35] !! Got S-frame while link down
[Dec 20 10:45:35] VERBOSE[2988428208]: [Dec 20 10:45:35]   == Primary D-Channel on span 1 up
[Dec 20 10:45:35] DEBUG[2988960688]: Device 'SIP/3017' changed to state '1' (Not in use)
[Dec 20 10:45:35] DEBUG[2988960688]: Device 'SIP/2224' changed to state '1' (Not in use)
[Dec 20 10:45:35] DEBUG[2988960688]: Device 'SIP/1313' changed to state '1' (Not in use)
[Dec 20 10:45:35] DEBUG[2988960688]: Device 'SIP/2228' changed to state '1' (Not in use)
[Dec 20 10:45:36] DEBUG[2988960688]: Device 'SIP/2225' changed to state '5' (Unavailable)
[Dec 20 10:45:36] DEBUG[2988960688]: Device 'SIP/104' changed to state '5' (Unavailable)
[Dec 20 10:45:38] NOTICE[3071273904]: Peer 'voipjet' is now UNREACHABLE! Time: 0
[Dec 20 10:45:38] DEBUG[2988960688]: Device 'IAX2/voipjet' changed to state '1' (Not in use)
[Dec 20 10:45:38] DEBUG[2982493104]: Device 'Zap/23' changed to state '2' (In use)
[Dec 20 10:45:38] DEBUG[2988960688]: Launching 'NoOp'
[Dec 20 10:45:38] VERBOSE[2988428208]: [Dec 20 10:45:38]     -- Accepting call from '5152883667' to '4715009' on channel 0/23, span 1
[Dec 20 10:45:38] DEBUG[2988428208]: Enabled echo cancellation on channel 23
[Dec 20 10:45:38] VERBOSE[2988960688]: [Dec 20 10:45:38]     -- Executing NoOp("Zap/23-1", "Conference participant number") in new stack
[Dec 20 10:45:38] DEBUG[2988960688]: Launching 'Wait'
[Dec 20 10:45:38] VERBOSE[2988960688]: [Dec 20 10:45:38]     -- Executing Wait("Zap/23-1", "1") in new stack
[Dec 20 10:45:39] DEBUG[2988960688]: Launching 'Answer'
[Dec 20 10:45:39] VERBOSE[2988960688]: [Dec 20 10:45:39]     -- Executing Answer("Zap/23-1", "") in new stack
[Dec 20 10:45:39] DEBUG[3079932848]: Avoiding initial deadlock for 'Zap/23-1'
[Dec 20 10:45:39] DEBUG[2988960688]: Launching 'Wait'
[Dec 20 10:45:39] VERBOSE[2988960688]: [Dec 20 10:45:39]     -- Executing Wait("Zap/23-1", "1") in new stack
[Dec 20 10:45:39] DEBUG[2982493104]: Device 'Zap/23' changed to state '2' (In use)
[Dec 20 10:45:40] DEBUG[2988960688]: Launching 'NoOp'
[Dec 20 10:45:40] VERBOSE[2988960688]: [Dec 20 10:45:40]     -- Executing NoOp("Zap/23-1", "Play greeting MVS Conference Services") in new stack
[Dec 20 10:45:40] DEBUG[2988960688]: Launching 'Playback'
[Dec 20 10:45:40] VERBOSE[2988960688]: [Dec 20 10:45:40]     -- Executing Playback("Zap/23-1", "welcome-to-conf-fac|skip") in new stack
[Dec 20 10:45:40] DEBUG[2988960688]: Trying to deactivate generator in Zap/23-1
[Dec 20 10:45:40] DEBUG[2988960688]: Generator on Zap/23-1 stopped after 0 iterations
[Dec 20 10:45:40] VERBOSE[2988960688]: [Dec 20 10:45:40]     -- Playing 'welcome-to-conf-fac' (language 'en')
[Dec 20 10:45:40] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:45:44] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:45:44] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:45:44] DEBUG[2988960688]: Launching 'Wait'
[Dec 20 10:45:44] VERBOSE[2988960688]: [Dec 20 10:45:44]     -- Executing Wait("Zap/23-1", "1") in new stack
[Dec 20 10:45:45] DEBUG[2987629488]: Stopping retransmission on '2aaa0a5d0ad98e80196058680146143d@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:45] DEBUG[2987629488]: Stopping retransmission on '4f907edb245d849d19209a85163b8371@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:45] DEBUG[2988960688]: Launching 'NoOp'
[Dec 20 10:45:45] VERBOSE[2988960688]: [Dec 20 10:45:45]     -- Executing NoOp("Zap/23-1", "starting Conference 4715009") in new stack
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/1 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/2 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/3 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/4 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/5 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/6 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/7 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/8 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/9 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/10 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/11 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/12 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/13 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/14 successfully restarted on span 1
[Dec 20 10:45:50] VERBOSE[2988428208]: [Dec 20 10:45:50]     -- B-channel 0/15 successfully restarted on span 1
[Dec 20 10:45:51] VERBOSE[2988428208]: [Dec 20 10:45:51]     -- B-channel 0/16 successfully restarted on span 1
[Dec 20 10:45:51] VERBOSE[2988428208]: [Dec 20 10:45:51]     -- B-channel 0/17 successfully restarted on span 1
[Dec 20 10:45:51] VERBOSE[2988428208]: [Dec 20 10:45:51]     -- B-channel 0/18 successfully restarted on span 1
[Dec 20 10:45:51] VERBOSE[2988428208]: [Dec 20 10:45:51]     -- B-channel 0/19 successfully restarted on span 1
[Dec 20 10:45:51] VERBOSE[2988428208]: [Dec 20 10:45:51]     -- B-channel 0/20 successfully restarted on span 1
[Dec 20 10:45:51] VERBOSE[2988428208]: [Dec 20 10:45:51]     -- B-channel 0/21 successfully restarted on span 1
[Dec 20 10:45:51] VERBOSE[2988428208]: [Dec 20 10:45:51]     -- B-channel 0/22 successfully restarted on span 1
[Dec 20 10:45:55] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:45:55] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:45:55] DEBUG[2987629488]: Stopping retransmission on '351558c11023b6464987cf593713d999@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:55] DEBUG[2987629488]: Stopping retransmission on '7741c2195d83ab2f51791e1d1d104113@10.0.0.19' of Request 102: Match Found
[Dec 20 10:45:56] VERBOSE[2988960688]: [Dec 20 10:45:56]     -- Timeout on Zap/23-1
[Dec 20 10:45:56] VERBOSE[2988960688]: [Dec 20 10:45:56]   == CDR updated on Zap/23-1
[Dec 20 10:45:56] DEBUG[2988960688]: Launching 'Goto'
[Dec 20 10:45:56] VERBOSE[2988960688]: [Dec 20 10:45:56]     -- Executing Goto("Zap/23-1", "#|1") in new stack
[Dec 20 10:45:56] VERBOSE[2988960688]: [Dec 20 10:45:56]     -- Goto (outbound,#,1)
[Dec 20 10:45:56] DEBUG[2988960688]: Launching 'Playback'
[Dec 20 10:45:56] VERBOSE[2988960688]: [Dec 20 10:45:56]     -- Executing Playback("Zap/23-1", "demo-thanks") in new stack
[Dec 20 10:45:56] DEBUG[2988960688]: Trying to deactivate generator in Zap/23-1
[Dec 20 10:45:56] DEBUG[2988960688]: Generator on Zap/23-1 stopped after 0 iterations
[Dec 20 10:45:56] WARNING[2988960688]: Unexpected freqency 44100
[Dec 20 10:45:56] WARNING[2988960688]: Unable to open file on /opt/openpbx.org/var/data/sounds/en_US/MelanieTaylor/demo-thanks.wav
[Dec 20 10:45:56] VERBOSE[2988960688]: [Dec 20 10:45:56]     -- Playing 'demo-thanks' (language 'en')
[Dec 20 10:45:58] DEBUG[2987629488]: Allocating new SIP dialog for bd489b9d-dc198689@172.16.25.101 - REGISTER (No RTP)
[Dec 20 10:45:58] DEBUG[2987629488]: SQL [delete from odb where family = 'SIP/Registry' and keys = '2228']
[Dec 20 10:45:59] DEBUG[2987629488]: SQL [insert into odb values('SIP/Registry','2228','172.16.25.101:5060:3600:2228:sip:2228@172.16.25.101:5060')]
[Dec 20 10:45:59] VERBOSE[2987629488]: [Dec 20 10:45:59]     -- Saved useragent "Sipura/SPA841-3.1.1(a)" for peer 2228
[Dec 20 10:45:59] DEBUG[2982493104]: Device 'SIP/2228' changed to state '1' (Not in use)
[Dec 20 10:46:00] VERBOSE[2988428208]: [Dec 20 10:46:00]     -- Channel 0/23, span 1 got hangup request
[Dec 20 10:46:00] WARNING[2988960688]: Failed to write frame
[Dec 20 10:46:00] DEBUG[2988960688]: Spawn extension (outbound,#,1) exited non-zero on 'Zap/23-1'
[Dec 20 10:46:00] VERBOSE[2988960688]: [Dec 20 10:46:00]   == Spawn extension (outbound, #, 1) exited non-zero on 'Zap/23-1'
[Dec 20 10:46:00] DEBUG[2988960688]: CDR SQLITE3 SQL [INSERT INTO cdr (clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata, start,answer,end,duration,billsec,disposition,amaflags, accountcode) VALUES ('5152883667', '5152883667', '#', 'outbound', 'Zap/23-1', '', 'Playback', 'demo-thanks', '2006-12-20 10:45:38', '2006-12-20 10:45:39', '2006-12-20 10:46:00', 22, 21, 4, 3, '')]
[Dec 20 10:46:00] DEBUG[2988960688]: Inserting a CDR record.
[Dec 20 10:46:00] DEBUG[2988960688]: SQL command executed:  INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-12-20 10:45:38','5152883667','5152883667','#','outbound', 'Zap/23-1','','Playback','demo-thanks',22,21,'ANSWERED',3,'','1166633138.0','')
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is '5152883667'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is '5152883667'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is '#'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is 'outbound'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is 'Zap/23-1'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is '(null)'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is 'Playback'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is 'demo-thanks'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is '2006-12-20 10:45:38'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is '2006-12-20 10:45:39'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is '2006-12-20 10:46:00'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is '22'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is '21'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is 'ANSWERED'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is 'DOCUMENTATION'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is '(null)'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is '1166633138.0'
[Dec 20 10:46:00] DEBUG[2988960688]: Function result is '(null)'
[Dec 20 10:46:00] DEBUG[2988960688]: Hanging up channel 'Zap/23-1'
[Dec 20 10:46:00] DEBUG[2988960688]: zt_hangup(Zap/23-1)
[Dec 20 10:46:00] DEBUG[2988960688]: Set option AUDIO MODE, value: ON(1) on Zap/23-1
[Dec 20 10:46:00] DEBUG[2988960688]: Hangup: channel: 23 index = 0, normal = 34, callwait = -1, thirdcall = -1
[Dec 20 10:46:00] DEBUG[2988960688]: Not yet hungup...  Calling hangup once with icause, and clearing call
[Dec 20 10:46:00] DEBUG[2988960688]: disabled echo cancellation on channel 23
[Dec 20 10:46:00] DEBUG[2988960688]: Set option TDD MODE, value: OFF(0) on Zap/23-1
[Dec 20 10:46:00] DEBUG[2988960688]: Updated conferencing on 23, with 0 conference users
[Dec 20 10:46:00] DEBUG[2988960688]: Set option AUDIO MODE, value: OFF(0) on Zap/23-1
[Dec 20 10:46:00] DEBUG[2988960688]: disabled echo cancellation on channel 23
[Dec 20 10:46:00] VERBOSE[2988960688]: [Dec 20 10:46:00]     -- Hungup 'Zap/23-1'
[Dec 20 10:46:00] DEBUG[2988960688]: Generator : deactivate after channel unlock (hangup function)
[Dec 20 10:46:00] DEBUG[2988960688]: Trying to deactivate generator in Zap/23-1
[Dec 20 10:46:00] DEBUG[2988960688]: Generator on Zap/23-1 stopped after 0 iterations
[Dec 20 10:46:00] DEBUG[2982493104]: Device 'Zap/23' changed to state '0' (Unknown)
[Dec 20 10:46:00] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:46:05] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:05] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:05] DEBUG[2987629488]: Stopping retransmission on '363ed5bd66506668081977b0513b037e@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:05] DEBUG[2987629488]: Stopping retransmission on '327726f85d21315567fabfd6015b183e@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:08] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:46:08] DEBUG[2987629488]: Stopping retransmission on '241dad2073ae2bfc180bb099312c4b1e@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:09] DEBUG[2987629488]: Allocating new SIP dialog for 538d891a991abc8f5c1dbbb9e17304e0-55ae664697f2@10.0.0.19 - INVITE (With RTP)
[Dec 20 10:46:09] DEBUG[2987629488]: * SIP extension value: 5 for call 538d891a991abc8f5c1dbbb9e17304e0-55ae664697f2@10.0.0.19
[Dec 20 10:46:09] DEBUG[2987629488]: *** Setting NAT on RTP to 1
[Dec 20 10:46:09] DEBUG[2987629488]: Setting NAT on VRTP to 1
[Dec 20 10:46:10] DEBUG[2987629488]: Stopping retransmission on '538d891a991abc8f5c1dbbb9e17304e0-55ae664697f2@10.0.0.19' of Response 77866: Match Found
[Dec 20 10:46:10] DEBUG[2987629488]: *** Setting NAT on RTP to 1
[Dec 20 10:46:10] DEBUG[2987629488]: Setting NAT on VRTP to 1
[Dec 20 10:46:10] DEBUG[2987629488]: Got this other party (o = '- 714982480 303318 IN IP4 10.7.1.207')
[Dec 20 10:46:10] DEBUG[2987629488]: Activating RTP on response 538d891a991abc8f5c1dbbb9e17304e0-55ae664697f2@10.0.0.19 (1)
[Dec 20 10:46:10] DEBUG[2987629488]: T38 state changed to 0 on channel <none>
[Dec 20 10:46:10] DEBUG[2987629488]: Checking SIP call limits for device 3017
[Dec 20 10:46:10] DEBUG[2987629488]: build_route: Contact hop: <sip:3017@10.7.1.207:5060>
[Dec 20 10:46:10] DEBUG[3079932848]: Avoiding initial deadlock for 'SIP/3017-239c'
[Dec 20 10:46:10] DEBUG[2988960688]: Launching 'NConference'
[Dec 20 10:46:10] VERBOSE[2988960688]: [Dec 20 10:46:10]     -- Executing NConference("SIP/3017-239c", "4001/MVq") in new stack
[Dec 20 10:46:10] DEBUG[2988960688]: sip_answer(SIP/3017-239c)
[Dec 20 10:46:10] DEBUG[2988960688]: attempting to parse passed params, stringp => 4001/MVq
[Dec 20 10:46:10] DEBUG[2988960688]: parsed data params, id => 4001, flags => MVq, pin 
[Dec 20 10:46:10] DEBUG[2988960688]: created member on channel SIP/3017-239c, type => 0, readformat => 4, writeformat => 4
[Dec 20 10:46:10] DEBUG[2988960688]: created member on channel SIP/3017-239c, type => 0, readformat => 4, writeformat => 4
[Dec 20 10:46:10] DEBUG[2988960688]: Allocating generator
[Dec 20 10:46:10] DEBUG[2988960688]: CHANNEL INFO, CHANNEL => SIP/3017-239c, DNID => 4001, CALLER_ID => 3017, ANI => (null)
[Dec 20 10:46:10] DEBUG[2988960688]: CHANNEL CODECS, CHANNEL => SIP/3017-239c, NATIVE => 4, READ => 64, WRITE => 64
[Dec 20 10:46:10] DEBUG[2988960688]: Set channel SIP/3017-239c to read format slin
[Dec 20 10:46:10] DEBUG[2988960688]: Set channel SIP/3017-239c to write format slin
[Dec 20 10:46:10] DEBUG[2988960688]: attempting to find requested conference
[Dec 20 10:46:10] DEBUG[2988960688]: conflist has not yet been initialized, name => 4001
[Dec 20 10:46:10] DEBUG[2988960688]: attempting to create requested conference
[Dec 20 10:46:10] DEBUG[2988960688]: entered create_conf, name => 4001
[Dec 20 10:46:10] DEBUG[2982493104]: Generator thread started on SIP/3017-239c
[Dec 20 10:46:10] DEBUG[2988960688]: Conference, name => 4001 - Added command 4 params: '1/3017'
[Dec 20 10:46:10] DEBUG[2988960688]: Conference, name => 4001 - Added command 3 params: '1/conf-hasjoin'
[Dec 20 10:46:10] DEBUG[2988960688]: member added to conference, name => 4001
[Dec 20 10:46:10] DEBUG[2988960688]: added new conference to conflist, name => 4001
[Dec 20 10:46:10] DEBUG[2988960688]: started conference thread for conference, name => 4001
[Dec 20 10:46:10] DEBUG[2988960688]: begin member event loop, channel => SIP/3017-239c
[Dec 20 10:46:10] DEBUG[2982161328]: Entered conference_exec, name => 4001
[Dec 20 10:46:10] DEBUG[2982161328]: Parsing Command Queue for conference 4001
[Dec 20 10:46:10] DEBUG[2981895088]: Device 'SIP/3017' changed to state '2' (In use)
[Dec 20 10:46:10] DEBUG[2982161328]: Parsing Command Queue for conference 4001
[Dec 20 10:46:10] DEBUG[2988960688]: Trying to deactivate generator in SIP/3017-239c
[Dec 20 10:46:10] DEBUG[2982493104]: Releasing generator
[Dec 20 10:46:10] DEBUG[2988960688]: Generator on SIP/3017-239c stopped after 1 iterations
[Dec 20 10:46:10] VERBOSE[2988960688]: [Dec 20 10:46:10]     -- Started music on hold, class 'default', on SIP/3017-239c
[Dec 20 10:46:10] DEBUG[2982493104]: Set channel SIP/3017-239c to write format ulaw
[Dec 20 10:46:10] DEBUG[2982493104]: SIP/3017-239c Opened file 0 '/opt/openpbx.org/var/data/moh/beethoven_violin_sonata_n7'
[Dec 20 10:46:10] DEBUG[2982493104]: Ooh, format changed from unknown to ulaw
[Dec 20 10:46:10] DEBUG[2982493104]: Had to change frame MS from 0 to 20
[Dec 20 10:46:10] DEBUG[2982493104]: Able to create smoother :) ms: 20 len 160
[Dec 20 10:46:10] DEBUG[2981895088]: Device 'SIP/3017' changed to state '2' (In use)
[Dec 20 10:46:10] DEBUG[2987629488]: Stopping retransmission on '538d891a991abc8f5c1dbbb9e17304e0-55ae664697f2@10.0.0.19' of Response 77867: Match Found
[Dec 20 10:46:10] DEBUG[2988960688]: MEMBER FRAME DATA: datalen 320  samples 160  len(ms) 20, offset: 64 
[Dec 20 10:46:10] DEBUG[2988960688]: Member on channel SIP/3017-239c. State changed to silent.
[Dec 20 10:46:14] DEBUG[3079666608]: Auto destroying call 'bd489b9d-dc198689@172.16.25.101'
[Dec 20 10:46:15] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:15] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:16] DEBUG[2987629488]: Stopping retransmission on '380669a25cfbfda16fa978935fe788bd@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:16] DEBUG[2987629488]: Stopping retransmission on '0604fd63091c4ba2299d8e26321aabf1@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:17] DEBUG[2988960688]: Trying to deactivate generator in SIP/3017-239c
[Dec 20 10:46:17] VERBOSE[2982493104]: [Dec 20 10:46:17]     -- Stopped music on hold on SIP/3017-239c
[Dec 20 10:46:17] DEBUG[2982493104]: Set channel SIP/3017-239c to write format slin
[Dec 20 10:46:17] DEBUG[2988960688]: Generator on SIP/3017-239c stopped after 1 iterations
[Dec 20 10:46:17] DEBUG[2988960688]: unable to read from channel, channel => SIP/3017-239c. Got Hangup.
[Dec 20 10:46:17] DEBUG[2988960688]: end member event loop, time_entered => 1166633170 -  removal: 1
[Dec 20 10:46:17] DEBUG[2988960688]: Trying to deactivate generator in SIP/3017-239c
[Dec 20 10:46:17] DEBUG[2988960688]: Generator on SIP/3017-239c stopped after 0 iterations
[Dec 20 10:46:17] DEBUG[2988960688]: Spawn extension (default,4001,1) exited non-zero on 'SIP/3017-239c'
[Dec 20 10:46:17] VERBOSE[2988960688]: [Dec 20 10:46:17]   == Spawn extension (default, 4001, 1) exited non-zero on 'SIP/3017-239c'
[Dec 20 10:46:17] DEBUG[2988960688]: CDR SQLITE3 SQL [INSERT INTO cdr (clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata, start,answer,end,duration,billsec,disposition,amaflags, accountcode) VALUES ('"Spackle - N. Smith" <3017>', '3017', '4001', 'default', 'SIP/3017-239c', '', 'NConference', '4001/MVq', '2006-12-20 10:46:10', '2006-12-20 10:46:10', '2006-12-20 10:46:17', 7, 7, 4, 3, '')]
[Dec 20 10:46:17] DEBUG[2982161328]: found member slated for removal, channel => SIP/3017-239c
[Dec 20 10:46:17] DEBUG[2982161328]: freeing member id, name => SIP/3017-239c
[Dec 20 10:46:17] DEBUG[2982161328]: freeing member flags, name => SIP/3017-239c
[Dec 20 10:46:17] DEBUG[2982161328]: freeing member pin, name => SIP/3017-239c
[Dec 20 10:46:17] DEBUG[2982161328]: freeing member circular buffer, name => SIP/3017-239c
[Dec 20 10:46:17] DEBUG[2982161328]: freeing member
[Dec 20 10:46:17] DEBUG[2982161328]: removed member from conference, name => 4001
[Dec 20 10:46:17] DEBUG[2982161328]: Conference, name => 4001 - Added command 4 params: '1/3017'
[Dec 20 10:46:17] DEBUG[2982161328]: Conference, name => 4001 - Added command 3 params: '1/conf-hasleft'
[Dec 20 10:46:17] DEBUG[2982161328]: removing conference, count => 0, name => 4001
[Dec 20 10:46:17] DEBUG[2982161328]: attempting to remove conference, name => 4001
[Dec 20 10:46:17] DEBUG[2982161328]: removed conference, name => 4001
[Dec 20 10:46:17] DEBUG[2982161328]: exit conference_exec
[Dec 20 10:46:17] DEBUG[2988960688]: Inserting a CDR record.
[Dec 20 10:46:17] DEBUG[2988960688]: SQL command executed:  INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-12-20 10:46:10','"Spackle - N. Smith" <3017>','3017','4001','default', 'SIP/3017-239c','','NConference','4001/MVq',7,7,'ANSWERED',3,'','1166633170.1','')
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '"Spackle - N. Smith" <3017>'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '3017'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '4001'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is 'default'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is 'SIP/3017-239c'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '(null)'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is 'NConference'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '4001/MVq'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '2006-12-20 10:46:10'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '2006-12-20 10:46:10'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '2006-12-20 10:46:17'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '7'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '7'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is 'ANSWERED'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is 'DOCUMENTATION'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '(null)'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '1166633170.1'
[Dec 20 10:46:18] DEBUG[2988960688]: Function result is '(null)'
[Dec 20 10:46:18] DEBUG[2988960688]: Hanging up channel 'SIP/3017-239c'
[Dec 20 10:46:18] DEBUG[2988960688]: Hangup call SIP/3017-239c, SIP callid 538d891a991abc8f5c1dbbb9e17304e0-55ae664697f2@10.0.0.19)
[Dec 20 10:46:18] DEBUG[2988960688]: update_call_counter(3017) - decrement call limit counter
[Dec 20 10:46:18] DEBUG[2988960688]: Generator : deactivate after channel unlock (hangup function)
[Dec 20 10:46:18] DEBUG[2988960688]: Trying to deactivate generator in SIP/3017-239c
[Dec 20 10:46:18] DEBUG[2988960688]: Generator on SIP/3017-239c stopped after 0 iterations
[Dec 20 10:46:18] DEBUG[2982493104]: Generator thread shut down on SIP/3017-239c
[Dec 20 10:46:18] DEBUG[2982493104]: Device 'SIP/3017' changed to state '1' (Not in use)
[Dec 20 10:46:20] DEBUG[2987629488]: Allocating new SIP dialog for 83c8d8cc16884c6d@10.9.9.103 - REGISTER (No RTP)
[Dec 20 10:46:20] DEBUG[2987629488]: SQL [delete from odb where family = 'SIP/Registry' and keys = '103']
[Dec 20 10:46:20] DEBUG[2987629488]: SQL [insert into odb values('SIP/Registry','103','10.9.9.103:5060:3600:103:sip:103@10.9.9.103;user=phone')]
[Dec 20 10:46:21] VERBOSE[2987629488]: [Dec 20 10:46:21]     -- Saved useragent "Grandstream BT110 1.0.8.33" for peer 103
[Dec 20 10:46:21] DEBUG[2982493104]: Device 'SIP/103' changed to state '1' (Not in use)
[Dec 20 10:46:24] DEBUG[3071273904]: Allocate call number
[Dec 20 10:46:24] DEBUG[3071273904]: Registration created on call 10
[Dec 20 10:46:24] DEBUG[3079666608]: Allocate call number
[Dec 20 10:46:24] DEBUG[3079666608]: Registration created on call 11
[Dec 20 10:46:26] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:26] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:26] DEBUG[2987629488]: Stopping retransmission on '4cd2853376991a29508a34553ae66e18@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:26] NOTICE[2987629488]: Peer '2225' is now REACHABLE! (185ms / 200ms)
[Dec 20 10:46:26] DEBUG[2982493104]: Device 'SIP/2225' changed to state '1' (Not in use)
[Dec 20 10:46:26] DEBUG[2987629488]: Stopping retransmission on '546547865677b99b0b3a55cc2abe4c6b@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:30] DEBUG[2987629488]: Allocating new SIP dialog for (No Call-ID) - NOTIFY (No RTP)
[Dec 20 10:46:30] DEBUG[2987629488]: Stopping retransmission on '79729e891e00717e76826456684d6614@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:34] DEBUG[2987629488]: Stopping retransmission on '735392ee7a8317e43f6750a87a4bab5c@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:34] DEBUG[3060747184]: Peer lastms 37, historicms 37, maxms 2000
[Dec 20 10:46:34] DEBUG[3060747184]: Peer lastms 43, historicms 43, maxms 2000
[Dec 20 10:46:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:34] DEBUG[2987629488]: Stopping retransmission on '1411be2677f1f48364858148165e99ac@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:34] DEBUG[2987629488]: Stopping retransmission on '5d0d5bce17f3c9e705515ef84fd0255e@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:34] DEBUG[2987629488]: Stopping retransmission on '1c2236be046f9cd2094dbd1511fe5b98@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:34] DEBUG[2987629488]: Stopping retransmission on '2d6094b43ee2e99306a4143034b5a534@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:34] DEBUG[2987629488]: Stopping retransmission on '724b0e371d095aa26be5542d2e6f79b5@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:34] DEBUG[2987629488]: Stopping retransmission on '4c3b6fbe7e8d84bc0ddb975c0cd3228e@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:34] DEBUG[3060747184]: Peer lastms 67, historicms 67, maxms 2000
[Dec 20 10:46:34] DEBUG[2987629488]: Stopping retransmission on '1a7cf9df055da7c877a461e564fd4762@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:34] DEBUG[2987629488]: Stopping retransmission on '0433209d2096b7ac46169a5e15340b35@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:34] DEBUG[2987629488]: Stopping retransmission on '4da7e3a64ff18f41060fd95772a3ee64@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:34] DEBUG[2987629488]: Stopping retransmission on '7246e1845a3842686191686e6fbe2ace@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:36] DEBUG[3071273904]: Auto destroying call '83c8d8cc16884c6d@10.9.9.103'
[Dec 20 10:46:36] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:36] DEBUG[2987629488]: Stopping retransmission on '2efe61455ef11a1203a2e2f91ba83ece@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:41] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:46:46] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:46] DEBUG[2987629488]: Stopping retransmission on '7304f1107f74db207cc02e1f0e1d3f45@10.0.0.19' of Request 102: Match Found
[Dec 20 10:46:56] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:46:57] DEBUG[2987629488]: Stopping retransmission on '538b84ee73cbdbd552ef1c5038b670fa@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:01] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:47:07] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:07] DEBUG[2987629488]: Stopping retransmission on '01eb7ddf7fc33c264d6b1fcc1d5caf0d@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:14] DEBUG[3071273904]: Allocate call number
[Dec 20 10:47:14] DEBUG[3071273904]: Registration created on call 3
[Dec 20 10:47:14] DEBUG[3071273904]: Allocate call number
[Dec 20 10:47:14] DEBUG[3071273904]: Registration created on call 4
[Dec 20 10:47:17] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:17] DEBUG[2987629488]: Stopping retransmission on '05fd8aec2c0831d20082526c5e01c2dc@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:21] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:47:26] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:26] DEBUG[2987629488]: Stopping retransmission on '2692639352dc72e701dad42c60cbee3f@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:27] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:27] DEBUG[2987629488]: Stopping retransmission on '040ab38e55550f5a485a006a47cedb8a@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:34] DEBUG[2987629488]: Stopping retransmission on '184e72ab340fe4661d3392d67ddf5592@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:34] DEBUG[2987629488]: Stopping retransmission on '0208f18c4f3c2a297d87679522d4b722@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:34] DEBUG[2987629488]: Stopping retransmission on '573031b83b9f02f03bb612f669fdd584@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:34] DEBUG[2987629488]: Stopping retransmission on '5202299a5e1478d159e4f2d64d12f894@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:34] DEBUG[2987629488]: Stopping retransmission on '7affe6e50803d90b482efdd64c1a5415@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:34] DEBUG[2987629488]: Stopping retransmission on '678fbaf538fa95757e314bcb16571e71@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:34] DEBUG[2987629488]: Stopping retransmission on '60d2e7b72561f161780e3a516226c82f@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:34] DEBUG[3060747184]: Peer lastms 174, historicms 174, maxms 2000
[Dec 20 10:47:34] DEBUG[3060747184]: Peer lastms 178, historicms 178, maxms 2000
[Dec 20 10:47:34] DEBUG[2987629488]: Stopping retransmission on '670ee0db3e06bd9314c1d67138e80f1c@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:34] DEBUG[2987629488]: Stopping retransmission on '5054b6347db835d278d2cea41a7fcb0a@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:34] DEBUG[2987629488]: Stopping retransmission on '382cd96a04d930bf7d8db9e676c4957a@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:34] DEBUG[2987629488]: Stopping retransmission on '6980d9064258939f39a2dc7934f7d8e1@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:36] NOTICE[3060747184]: Peer 'isolver' is now TOO LAGGED (2163 ms)!
[Dec 20 10:47:36] DEBUG[2982493104]: Device 'IAX2/isolver' changed to state '5' (Unavailable)
[Dec 20 10:47:36] DEBUG[3060747184]: Peer lastms 2163, historicms 2163, maxms 2000
[Dec 20 10:47:37] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:38] DEBUG[2987629488]: Stopping retransmission on '1add567f0802a90d08212488208e12af@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:41] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:47:46] NOTICE[3060747184]: Peer 'isolver' is now REACHABLE! Time: 36
[Dec 20 10:47:46] DEBUG[2982493104]: Device 'IAX2/isolver' changed to state '1' (Not in use)
[Dec 20 10:47:46] DEBUG[3060747184]: Peer lastms 36, historicms 36, maxms 2000
[Dec 20 10:47:48] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:48] DEBUG[2987629488]: Stopping retransmission on '7e4477e40628498c5ae250d731a549af@10.0.0.19' of Request 102: Match Found
[Dec 20 10:47:58] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:47:58] DEBUG[2987629488]: Stopping retransmission on '200d9cc37a67ea9a5cc6117d07533635@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:01] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:48:04] DEBUG[3079666608]: Allocate call number
[Dec 20 10:48:04] DEBUG[3079666608]: Registration created on call 1
[Dec 20 10:48:04] DEBUG[3079666608]: Allocate call number
[Dec 20 10:48:04] DEBUG[3079666608]: Registration created on call 10
[Dec 20 10:48:08] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:09] DEBUG[2987629488]: Stopping retransmission on '516279b050dc85ac1d698a3d4734eb41@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:19] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:19] DEBUG[2987629488]: Stopping retransmission on '31e58b2005d8509043c8eb841a1f9572@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:21] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:48:26] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:26] DEBUG[2987629488]: Stopping retransmission on '1927fffc69b7ee52049544d10c97edde@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:26] NOTICE[2987629488]: Peer '2225' is now TOO LAGGED! (311ms / 200ms)
[Dec 20 10:48:26] DEBUG[2982493104]: Device 'SIP/2225' changed to state '5' (Unavailable)
[Dec 20 10:48:29] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:29] DEBUG[2987629488]: Stopping retransmission on '2fe2e1aa22e449022128c0e727510a73@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:34] DEBUG[2987629488]: Stopping retransmission on '4eecf2365c4d221522956111634896e2@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:34] DEBUG[2987629488]: Stopping retransmission on '236f2c9b4d7bacb16e4cc2415d1b0bbb@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:34] DEBUG[2987629488]: Stopping retransmission on '20de1a122ef2bffe578730f40f24dc41@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:34] DEBUG[2987629488]: Stopping retransmission on '4518ab3d44b489cf79484141337ddd57@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:34] DEBUG[2987629488]: Stopping retransmission on '1002539524bb65fc5a028b127c549564@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:34] DEBUG[2987629488]: Stopping retransmission on '1aae0cd31ce1681e50ba0d185c371ec2@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:34] DEBUG[2987629488]: Stopping retransmission on '4e2b0b9251813f384f3f5d7829c38d35@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:34] DEBUG[3060747184]: Peer lastms 43, historicms 43, maxms 2000
[Dec 20 10:48:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:34] DEBUG[3060747184]: Peer lastms 65, historicms 65, maxms 2000
[Dec 20 10:48:34] DEBUG[2987629488]: Stopping retransmission on '1c97df365b2f85606aa3b1371781674b@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:34] DEBUG[2987629488]: Stopping retransmission on '7fb6161717747f3c350b38f2166ade2b@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:34] DEBUG[2987629488]: Stopping retransmission on '38a44f8c1a814e91167681282b93b3bb@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:35] DEBUG[2987629488]: Stopping retransmission on '5b044390365c7df935c994c665198d3c@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:36] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:36] DEBUG[2987629488]: Stopping retransmission on '1d18033163dc69bc00ef690f6cef5a98@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:36] NOTICE[2987629488]: Peer '2225' is now REACHABLE! (186ms / 200ms)
[Dec 20 10:48:36] DEBUG[2982493104]: Device 'SIP/2225' changed to state '1' (Not in use)
[Dec 20 10:48:39] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:39] DEBUG[2987629488]: Stopping retransmission on '2fd613a36a8decbc1c362c40714d9860@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:41] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:48:46] DEBUG[3060747184]: Peer lastms 75, historicms 75, maxms 2000
[Dec 20 10:48:49] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:48:50] DEBUG[2987629488]: Stopping retransmission on '5ecef6f016dd5c6e7dde81ea3c66d85b@10.0.0.19' of Request 102: Match Found
[Dec 20 10:48:54] DEBUG[3079666608]: Allocate call number
[Dec 20 10:48:54] DEBUG[3079666608]: Registration created on call 6
[Dec 20 10:48:54] DEBUG[3079666608]: Allocate call number
[Dec 20 10:48:54] DEBUG[3079666608]: Registration created on call 8
[Dec 20 10:49:00] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:00] DEBUG[2987629488]: Stopping retransmission on '2985ca647fa8379e1a7f2ea72e9e66f2@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:01] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:49:10] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:10] DEBUG[2987629488]: Stopping retransmission on '580460431497df3f4d7ff39f7bc9f255@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:20] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:20] DEBUG[2987629488]: Stopping retransmission on '73b95e9f65c3f83202dbfb6366b8651f@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:21] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:49:30] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:31] DEBUG[2987629488]: Stopping retransmission on '1fe039946449451a141f58bd7ead4579@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:34] DEBUG[2987629488]: Stopping retransmission on '32476fc956d0ab6212db4e465a79f9ca@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:34] DEBUG[2987629488]: Stopping retransmission on '17342745075b38aa0ded283b266930a3@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:34] DEBUG[2987629488]: Stopping retransmission on '5d3b111f202f59c4483d2fa62798d43e@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:34] DEBUG[2987629488]: Stopping retransmission on '795027d92d1e43930c801307164ab71c@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:34] DEBUG[2987629488]: Stopping retransmission on '5a37db3141dfa95f1676d226204a6923@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:34] DEBUG[2987629488]: Stopping retransmission on '38891f8b536c91455f9d9b5e7faf56a8@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:34] DEBUG[2987629488]: Stopping retransmission on '248a81d75dd372912df9bfba7bfe8ecd@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:34] DEBUG[3060747184]: Peer lastms 43, historicms 43, maxms 2000
[Dec 20 10:49:34] DEBUG[3060747184]: Peer lastms 52, historicms 52, maxms 2000
[Dec 20 10:49:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:35] DEBUG[2987629488]: Stopping retransmission on '21df13a20bf574ef24aa3d2f339a8202@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:35] DEBUG[2987629488]: Stopping retransmission on '7534d0e927cd08073ef32be349d2ae5f@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:35] DEBUG[2987629488]: Stopping retransmission on '43331d8e5e937fb30e8bc1180c03f61c@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:35] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:35] DEBUG[2987629488]: Stopping retransmission on '2d848d6168056ed2099871794b0badb4@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:36] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:37] DEBUG[2987629488]: Stopping retransmission on '7677a2f72c32dc2c5a4ffac73ab4892c@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:37] NOTICE[2987629488]: Peer '2225' is now TOO LAGGED! (253ms / 200ms)
[Dec 20 10:49:37] DEBUG[2982493104]: Device 'SIP/2225' changed to state '5' (Unavailable)
[Dec 20 10:49:41] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:41] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:49:41] DEBUG[2987629488]: Stopping retransmission on '09a4ace25cff8b360c72b85c531a0cc8@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:44] DEBUG[3079666608]: Allocate call number
[Dec 20 10:49:44] DEBUG[3079666608]: Registration created on call 1
[Dec 20 10:49:44] DEBUG[3079666608]: Allocate call number
[Dec 20 10:49:44] DEBUG[3079666608]: Registration created on call 2
[Dec 20 10:49:46] DEBUG[3060747184]: Peer lastms 45, historicms 45, maxms 2000
[Dec 20 10:49:47] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:47] DEBUG[2987629488]: Stopping retransmission on '57c65de46483212e4d3871c02f3dea2b@10.0.0.19' of Request 102: Match Found
[Dec 20 10:49:47] NOTICE[2987629488]: Peer '2225' is now REACHABLE! (190ms / 200ms)
[Dec 20 10:49:47] DEBUG[2982493104]: Device 'SIP/2225' changed to state '1' (Not in use)
[Dec 20 10:49:51] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:49:51] DEBUG[2987629488]: Stopping retransmission on '22be039e554f8f722810750a430e8a49@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:01] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:50:01] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:01] DEBUG[2987629488]: Stopping retransmission on '080f228d103c9cdc5a49c08b3acdb660@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:11] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:12] DEBUG[2987629488]: Stopping retransmission on '26088d733c3fe2bf52268eb32c8ed8db@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:21] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:50:22] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:22] DEBUG[2987629488]: Stopping retransmission on '05a18331745c475b7e00f43d5b007f73@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:32] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:32] DEBUG[2987629488]: Stopping retransmission on '1cd6416341021d4518c87b297d4b9c57@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:34] DEBUG[3079666608]: Allocate call number
[Dec 20 10:50:34] DEBUG[3079666608]: Registration created on call 8
[Dec 20 10:50:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:34] DEBUG[2987629488]: Stopping retransmission on '26780eb8629584102ab6ef83781e786c@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:34] DEBUG[2987629488]: Stopping retransmission on '60ba1dfc368ac9fe562e24603047a7ce@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:34] DEBUG[2987629488]: Stopping retransmission on '3776868c60ffd952453db5451b65542a@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:34] DEBUG[2987629488]: Stopping retransmission on '704b83161615481a06eabad268885c94@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:34] DEBUG[2987629488]: Stopping retransmission on '417d1e6a28f0563a637d9ad33f27794a@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:34] DEBUG[2987629488]: Stopping retransmission on '2663ddf741405a01316c657e49a8e605@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:34] DEBUG[2987629488]: Stopping retransmission on '2b029b877586a99e6f48a1e0276c404d@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:34] DEBUG[3060747184]: Peer lastms 42, historicms 42, maxms 2000
[Dec 20 10:50:34] DEBUG[3060747184]: Peer lastms 31, historicms 31, maxms 2000
[Dec 20 10:50:34] DEBUG[3079666608]: Allocate call number
[Dec 20 10:50:34] DEBUG[3079666608]: Registration created on call 14
[Dec 20 10:50:35] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:35] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:35] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:35] DEBUG[2987629488]: Stopping retransmission on '493218cb6c0f408f49ba1eb36301122f@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:35] DEBUG[2987629488]: Stopping retransmission on '25e051913021b9fd76a305290f4adf07@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:35] DEBUG[2987629488]: Stopping retransmission on '038d5c7254ba475b4338278837578ae6@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:35] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:35] DEBUG[2987629488]: Stopping retransmission on '1b390e0b34fa90b86c10b6173ffd1cd9@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:41] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:50:42] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:42] DEBUG[2987629488]: Stopping retransmission on '4b287e244cc306ea4743ea28683cdc1f@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:46] DEBUG[3060747184]: Peer lastms 36, historicms 36, maxms 2000
[Dec 20 10:50:47] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:47] DEBUG[2987629488]: Stopping retransmission on '27a29b6e085330a032e063af3e27b4ba@10.0.0.19' of Request 102: Match Found
[Dec 20 10:50:52] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:50:53] DEBUG[2987629488]: Stopping retransmission on '1cd61bc8642b2b6d4195832d25ea95be@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:01] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:51:03] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:03] DEBUG[2987629488]: Stopping retransmission on '219fbd4b15d504256b0a2452057cf9c4@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:13] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:13] DEBUG[2987629488]: Stopping retransmission on '503927b824740bc737d6692063166d6b@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:21] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:51:23] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:24] DEBUG[2987629488]: Stopping retransmission on '540c8f534782aa9f12ab28c35f6e2fad@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:24] DEBUG[3079666608]: Allocate call number
[Dec 20 10:51:24] DEBUG[3079666608]: Registration created on call 1
[Dec 20 10:51:25] DEBUG[3071273904]: Allocate call number
[Dec 20 10:51:25] DEBUG[3071273904]: Registration created on call 3
[Dec 20 10:51:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:34] DEBUG[2987629488]: Stopping retransmission on '06e01572289e41745040dce358940d83@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:34] DEBUG[2987629488]: Stopping retransmission on '62e7655542c3855c05a0b7924b6d46cb@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:34] DEBUG[2987629488]: Stopping retransmission on '3fe77b6340fc0797515b72d2363c6fce@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:34] DEBUG[2987629488]: Stopping retransmission on '518014150bb46a757d404bbb0e9f62a1@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:34] DEBUG[2987629488]: Stopping retransmission on '46fdbe4a6658809045b05faf79f3dfae@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:34] DEBUG[2987629488]: Stopping retransmission on '18b4846d2428f5a06dc51b8e375b113f@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:34] DEBUG[2987629488]: Stopping retransmission on '44f0f6926ba310687a92065d754c4e79@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:34] DEBUG[2987629488]: Stopping retransmission on '40ee01b129316444759ff24403a40372@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:35] DEBUG[3060747184]: Peer lastms 167, historicms 167, maxms 2000
[Dec 20 10:51:35] DEBUG[3060747184]: Peer lastms 143, historicms 143, maxms 2000
[Dec 20 10:51:35] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:35] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:35] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:35] DEBUG[2987629488]: Stopping retransmission on '3cee35c615a98b5873e1daae0d6f4d64@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:35] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:35] DEBUG[2987629488]: Stopping retransmission on '3561d8010b652c5405dc8c6d382a55a7@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:35] DEBUG[2987629488]: Stopping retransmission on '147c17c13198b40068e1182f74360bb1@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:35] DEBUG[2987629488]: Stopping retransmission on '3670fe896cbc67632d1daa83745f0316@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:41] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:51:44] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:44] DEBUG[2987629488]: Stopping retransmission on '7a04e2647774970441a9afa76ec62d9f@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:46] DEBUG[3060747184]: Peer lastms 57, historicms 57, maxms 2000
[Dec 20 10:51:47] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:47] DEBUG[2987629488]: Stopping retransmission on '4d66481006d5c58a75bb375d24882494@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:47] NOTICE[2987629488]: Peer '2225' is now TOO LAGGED! (278ms / 200ms)
[Dec 20 10:51:47] DEBUG[2982493104]: Device 'SIP/2225' changed to state '5' (Unavailable)
[Dec 20 10:51:54] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:55] DEBUG[2987629488]: Stopping retransmission on '55e2c1b0479806284501b5163fabafc0@10.0.0.19' of Request 102: Match Found
[Dec 20 10:51:57] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:51:58] DEBUG[2987629488]: Stopping retransmission on '262b698f4e6b66415d03e384314cc076@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:01] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:52:05] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:05] DEBUG[2987629488]: Stopping retransmission on '641022973bc6a0a508c96d2d5fe387fb@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:08] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:08] DEBUG[2987629488]: Stopping retransmission on '4b7b732f1a7d1cd220d9d7b44021a8b5@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:14] DEBUG[3079666608]: Allocate call number
[Dec 20 10:52:14] DEBUG[3079666608]: Registration created on call 8
[Dec 20 10:52:15] DEBUG[3079666608]: Allocate call number
[Dec 20 10:52:15] DEBUG[3079666608]: Registration created on call 11
[Dec 20 10:52:15] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:15] DEBUG[2987629488]: Stopping retransmission on '68335b881c199f9a53a3e71f42c0d901@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:18] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:18] DEBUG[2987629488]: Stopping retransmission on '03f092565cf225134b9d43282e2a3beb@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:21] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:52:25] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:26] DEBUG[2987629488]: Stopping retransmission on '1ec052c65df09bfb554b3ad71a3465ff@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:28] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:29] DEBUG[2987629488]: Stopping retransmission on '7316e6c120ad042642792d3c2b530024@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:34] DEBUG[2987629488]: Stopping retransmission on '69921b7b19c0b3e63e4e4f68471a8806@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:34] DEBUG[2987629488]: Stopping retransmission on '113a7768047f492d668a4891273b78e8@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:34] DEBUG[2987629488]: Stopping retransmission on '27d661c4348e7fbe65cec24c2b601e3b@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:34] DEBUG[2987629488]: Stopping retransmission on '7ae8fc79249fd18915eeacc14c3f3d0f@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:34] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:34] DEBUG[2987629488]: Stopping retransmission on '0a47f5574aa7c4e65972fab64542140a@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:34] DEBUG[2987629488]: Stopping retransmission on '4a3acedb0af8129e52a101477e5a1288@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:34] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:34] DEBUG[2987629488]: Stopping retransmission on '158c5ef409d233a06856ed6612571a5b@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:35] DEBUG[3060747184]: Peer lastms 89, historicms 89, maxms 2000
[Dec 20 10:52:35] DEBUG[3060747184]: Peer lastms 74, historicms 74, maxms 2000
[Dec 20 10:52:35] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:35] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:35] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:35] DEBUG[2987629488]: Stopping retransmission on '06d75b14550b556e3f58ef637d4a7077@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:35] DEBUG[2987629488]: Stopping retransmission on '711533752349f6573270de4b0d350968@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:35] DEBUG[2987629488]: Stopping retransmission on '025758b13b02287359198e3415f146ba@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:35] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:35] DEBUG[2987629488]: Stopping retransmission on '75d3261a101bfb2458c6b1b814884f0e@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:36] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:36] DEBUG[2987629488]: Stopping retransmission on '72095c7c1858e70d25299f311b8c72d0@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:39] DEBUG[3071273904]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:39] DEBUG[2987629488]: Stopping retransmission on '272e555708d2a5264a164a3f1c9466c0@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:41] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:52:46] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:46] DEBUG[2987629488]: Stopping retransmission on '4f396e784d3639055c0c7eb912b92632@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:47] DEBUG[3060747184]: Peer lastms 49, historicms 49, maxms 2000
[Dec 20 10:52:49] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:49] DEBUG[2987629488]: Stopping retransmission on '623e53137861c382359a1d0c6dbb730f@10.0.0.19' of Request 102: Match Found
[Dec 20 10:52:49] NOTICE[2987629488]: Peer '2225' is now REACHABLE! (194ms / 200ms)
[Dec 20 10:52:49] DEBUG[2982493104]: Device 'SIP/2225' changed to state '1' (Not in use)
[Dec 20 10:52:56] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:52:56] DEBUG[2987629488]: Stopping retransmission on '7b312aa326464a8f1c032f616b330ee9@10.0.0.19' of Request 102: Match Found
[Dec 20 10:53:01] DEBUG[2987629488]: Runt STUN packet (only 4, wanting at least 20)
[Dec 20 10:53:04] DEBUG[3079666608]: Allocate call number
[Dec 20 10:53:04] DEBUG[3079666608]: Registration created on call 1
[Dec 20 10:53:05] DEBUG[3079666608]: Allocate call number
[Dec 20 10:53:05] DEBUG[3079666608]: Registration created on call 2
[Dec 20 10:53:06] DEBUG[3079666608]: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP)
[Dec 20 10:53:07] DEBUG[2987629488]: Stopping retransmission on '29b3e4876166868917733b143359b40d@10.0.0.19' of Request 102: Match Found