Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Setting NAT on RTP to 0 Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Checking SIP call limits for device 161 Feb 14 09:03:01 DEBUG[4829] chan_sip.c: build_route: Contact hop: ;flow-id=1 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing Macro("SIP/161-516e", "exten-vm|novm|116") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing Set("SIP/161-516e", "LANGUAGE()=de") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing Macro("SIP/161-516e", "user-callerid") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing DBget("SIP/161-516e", "AMPUSER=DEVICE/161/user") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- DBget: varname=AMPUSER, family=DEVICE, key=161/user Feb 14 09:03:01 VERBOSE[17619] logger.c: -- DBget: set variable AMPUSER to 161 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing DBget("SIP/161-516e", "AMPUSERCIDNAME=AMPUSER/161/cidname") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- DBget: varname=AMPUSERCIDNAME, family=AMPUSER, key=161/cidname Feb 14 09:03:01 VERBOSE[17619] logger.c: -- DBget: set variable AMPUSERCIDNAME to Waltraud Pfahler Feb 14 09:03:01 DEBUG[17619] pbx.c: Expression result is '0' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing GotoIf("SIP/161-516e", "0?5") in new stack Feb 14 09:03:01 DEBUG[17619] pbx.c: Not taking any branch Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing SetCallerID("SIP/161-516e", ""Waltraud Pfahler" <161>") in new stack Feb 14 09:03:01 DEBUG[17619] pbx.c: Function result is 'Waltraud Pfahler' Feb 14 09:03:01 DEBUG[17619] pbx.c: Expression result is '1' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing GotoIf("SIP/161-516e", "1?7") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Goto (macro-user-callerid,s,7) Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing NoOp("SIP/161-516e", "Using CallerID "Waltraud Pfahler" <161>") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing Macro("SIP/161-516e", "dnd-announce") in new stack Feb 14 09:03:01 DEBUG[17619] pbx.c: Expression result is '0' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing GotoIf("SIP/161-516e", "0?6") in new stack Feb 14 09:03:01 DEBUG[17619] pbx.c: Not taking any branch Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing Set("SIP/161-516e", "DND_ANNOUNCE=YES") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing DBget("SIP/161-516e", "DND_STATUS=DND/161") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- DBget: varname=DND_STATUS, family=DND, key=161 Feb 14 09:03:01 DEBUG[17619] db.c: Unable to find key '161' in family 'DND' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- DBget: Value not found in database. Feb 14 09:03:01 DEBUG[17619] pbx.c: Expression result is '0' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing GotoIf("SIP/161-516e", "0?5:6") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Goto (macro-dnd-announce,s,6) Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing NoOp("SIP/161-516e", "s") in new stack Feb 14 09:03:01 DEBUG[17619] pbx.c: Expression result is '1' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing GotoIf("SIP/161-516e", "1?5") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Goto (macro-exten-vm,s,5) Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing SetVar("SIP/161-516e", "FROMCONTEXT=exten-vm") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing Macro("SIP/161-516e", "record-enable|116|IN") in new stack Feb 14 09:03:01 DEBUG[17619] pbx.c: Function result is '0' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing GotoIf("SIP/161-516e", "0 > 0?2:4") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Goto (macro-record-enable,s,4) Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing NoOp("SIP/161-516e", "Caller Num 161 Dialed 116") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing AGI("SIP/161-516e", "recordingcheck|20060214-090301|1139904181.1264|161|116") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c832-3luww5zb7v07@snom360-000413232742' of Request 120: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009d949-tzvfcerbgqxt@snom360-0004132324D7' of Request 126: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009b71b-liq52ky5y2cb@snom360-00041323230D' of Request 121: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c26700a0000-qwu6ehy5ocrf@snom360-0004132328CA' of Request 122: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c350-ecn3vk63yg7e@snom360-0004132324D2' of Request 126: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009d467-m5aeza92flmd@snom360-000413232740' of Request 126: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009e57e-lscg8vtpt62a@snom360-0004132328D5' of Request 126: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c5c1-jcryt9n2ttkr@snom360-000413231F0E' of Request 121: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c26700a41eb-ibwc6piqzng7@snom360-0004132328B1' of Request 122: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009e57e-trwspjyh25ht@snom360-000413231F12' of Request 123: Match Found Feb 14 09:03:01 VERBOSE[17619] logger.c: recordingcheck|20060214-090301|1139904181.1264|161|116: Inbound recording not enabled Feb 14 09:03:01 VERBOSE[17619] logger.c: -- AGI Script recordingcheck completed, returning 0 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing NoOp("SIP/161-516e", "No recording needed "" is call filename ") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing Macro("SIP/161-516e", "dial|45|wrt|116") in new stack Feb 14 09:03:01 DEBUG[17619] pbx.c: Expression result is '0' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing GotoIf("SIP/161-516e", "0?4:2") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Goto (macro-dial,s,2) Feb 14 09:03:01 DEBUG[17619] pbx.c: Function result is '0' Feb 14 09:03:01 DEBUG[17619] pbx.c: Expression result is '0' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing GotoIf("SIP/161-516e", "0?5:4") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Goto (macro-dial,s,4) Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing AGI("SIP/161-516e", "dialparties.agi") in new stack Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: priority = 4 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: callingani2 = 0 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: accountcode = Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: channel = SIP/161-516e Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: callerid = 161 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: context = macro-dial Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: callington = 0 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: dnid = 116 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: request = dialparties.agi Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: calleridname = Waltraud Pfahler Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: extension = s Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: language = de Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: uniqueid = 1139904181.1264 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: callingpres = 0 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: type = SIP Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: rdnis = unknown Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: callingtns = 0 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: enhanced = 0.0 Feb 14 09:03:01 VERBOSE[17619] logger.c: dialparties.agi: Caller ID name and number are '161' Feb 14 09:03:01 VERBOSE[17619] logger.c: dialparties.agi: Methodology of ring is 'none' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: Added extension 116 to extension map Feb 14 09:03:01 DEBUG[17619] db.c: Unable to find key '116' in family 'CF' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: Extension 116 cf is disabled Feb 14 09:03:01 DEBUG[17619] db.c: Unable to find key '116' in family 'DND' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: Extension 116 do not disturb is disabled Feb 14 09:03:01 DEBUG[17619] db.c: Unable to find key '116' in family 'CW' Feb 14 09:03:01 DEBUG[17619] db.c: Unable to find key '116' in family 'CFB' Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 116 Feb 14 09:03:01 DEBUG[17623] manager.c: Manager received command 'Login' Feb 14 09:03:01 VERBOSE[17623] logger.c: == Parsing '/etc/asterisk/manager.conf': Feb 14 09:03:01 VERBOSE[17623] logger.c: == Parsing '/etc/asteri$ Feb 14 09:03:01 VERBOSE[17623] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Feb 14 09:03:01 VERBOSE[17623] logger.c: == Parsing '/etc$ Feb 14 09:03:01 WARNING[17623] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf Feb 14 09:03:01 DEBUG[17623] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer Feb 14 09:03:01 DEBUG[17623] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer Feb 14 09:03:01 DEBUG[17623] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 Feb 14 09:03:01 DEBUG[17623] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0 Feb 14 09:03:01 VERBOSE[17623] logger.c: == Manager 'admin' logged on from 127.0.0.1 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: Correct AMPMGRUSER and AMPMGRPASS Feb 14 09:03:01 DEBUG[17623] manager.c: Manager received command 'ExtensionState' Feb 14 09:03:01 DEBUG[17623] manager.c: Manager received command 'Logoff' Feb 14 09:03:01 VERBOSE[17623] logger.c: == Manager 'admin' logged off from 127.0.0.1 Feb 14 09:03:01 VERBOSE[17619] logger.c: dialparties.agi: Extension 116 is available...skipping checks Feb 14 09:03:01 VERBOSE[17619] logger.c: -- dialparties.agi: DbSet CALLTRACE/116 to 161 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- AGI Script dialparties.agi completed, returning 0 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Executing Dial("SIP/161-516e", "SIP/116|45|wrt") in new stack Feb 14 09:03:01 DEBUG[17619] chan_sip.c: Setting NAT on RTP to 0 Feb 14 09:03:01 DEBUG[17619] chan_sip.c: Outgoing Call for 116 Feb 14 09:03:01 VERBOSE[17619] logger.c: -- Called 116 Feb 14 09:03:01 DEBUG[4829] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '047a7c4c78e1f84b30d2c5f3173bdf36@192.168.4.2'$ Feb 14 09:03:01 DEBUG[4829] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '047a7c4c78e1f84b30d2c5f3173bdf36@192.168.4.2'$ Feb 14 09:03:01 VERBOSE[17619] logger.c: -- SIP/116-b4ee is ringing Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c832-locpuytqrifi@snom360-000413232742' of Request 111: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009d6d8-5z107i2tjceh@snom360-0004132324D7' of Request 114: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c0df-1d6jh25idioe@snom360-0004132324D2' of Request 114: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009d1f6-9vgl2g8u0b34@snom360-000413232740' of Request 114: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009e57e-7gfpzjbgjcwy@snom360-0004132328D5' of Request 114: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009e30d-duzaqvfyn5sj@snom360-000413231F12' of Request 113: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c5c1-pm968bfxh49k@snom360-000413231F0E' of Request 111: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009b71b-qlcdngk0a8ie@snom360-00041323230D' of Request 111: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c26700a0000-vnzf21gin77n@snom360-0004132328CA' of Request 112: Match Found Feb 14 09:03:01 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c26700a41eb-jvedwbuutm0p@snom360-0004132328B1' of Request 112: Match Found Feb 14 09:03:06 ERROR[4829] chan_sip.c: Got SUBSCRIBE for extensions without hint. Please add hint to 091132391810 in context from-internal Feb 14 09:03:06 ERROR[4829] chan_sip.c: Got SUBSCRIBE for extensions without hint. Please add hint to 09112342260 in context from-internal Feb 14 09:03:06 ERROR[4829] chan_sip.c: Got SUBSCRIBE for extensions without hint. Please add hint to 091123422621 in context from-internal Feb 14 09:03:06 ERROR[4829] chan_sip.c: Got SUBSCRIBE for extensions without hint. Please add hint to 091123422627 in context from-internal Feb 14 09:03:06 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009ad57-fqdqvob8zebz@snom360-00041323230D' of Request 107: Match Found Feb 14 09:03:06 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009ad57-j6quy9s9870g@snom360-00041323230D' of Request 111: Match Found Feb 14 09:03:06 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009afc8-h7vt0n103fnm@snom360-00041323230D' of Request 112: Match Found Feb 14 09:03:06 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009b239-9t7sc0sst1d9@snom360-00041323230D' of Request 103: Match Found Feb 14 09:03:06 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009b4aa-3ci5a1w09f1u@snom360-00041323230D' of Request 121: Match Found Feb 14 09:03:06 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009b71b-qlcdngk0a8ie@snom360-00041323230D' of Request 112: Match Found Feb 14 09:03:06 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009b98c-i7q83mdw3s5u@snom360-00041323230D' of Request 107: Match Found Feb 14 09:03:06 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009be6e-befp15zs6q7w@snom360-00041323230D' of Request 112: Match Found Feb 14 09:03:06 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c350-m0o0xabc6o7q@snom360-00041323230D' of Request 111: Match Found Feb 14 09:03:06 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009b71b-liq52ky5y2cb@snom360-00041323230D' of Request 122: Match Found Feb 14 09:03:06 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009bbfd-zj7d0uppohgs@snom360-00041323230D' of Request 107: Match Found Feb 14 09:03:06 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009bbfd-7ylxnue36q71@snom360-00041323230D' of Request 103: Match Found Feb 14 09:03:08 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009d1f6-ic9v0g7w3ghb@snom360-0004132324D7' of Request 112: Match Found Feb 14 09:03:08 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009e09c-ewuv1535ee1m@snom360-000413232740' of Request 111: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c0df-1sweus8l9b26@snom360-00041323230D' of Request 103: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Acked pending invite 102 Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '047a7c4c78e1f84b30d2c5f3173bdf36@192.168.4.2' of Request 102: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: build_route: Contact hop: First Call 2 Feb 14 09:03:13 VERBOSE[17619] logger.c: -- SIP/116-b4ee answered SIP/161-516e Feb 14 09:03:13 VERBOSE[17619] logger.c: -- Attempting native bridge of SIP/161-516e and SIP/116-b4ee Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c2bdb95a875-odt7zjfga16l@snom360-0004132328B1' of Response 1: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c5c1-pm968bfxh49k@snom360-000413231F0E' of Request 112: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c832-locpuytqrifi@snom360-000413232742' of Request 112: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009e30d-duzaqvfyn5sj@snom360-000413231F12' of Request 114: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009e57e-7gfpzjbgjcwy@snom360-0004132328D5' of Request 115: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c0df-1d6jh25idioe@snom360-0004132324D2' of Request 115: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009d6d8-5z107i2tjceh@snom360-0004132324D7' of Request 115: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009d1f6-9vgl2g8u0b34@snom360-000413232740' of Request 115: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c26700a0000-vnzf21gin77n@snom360-0004132328CA' of Request 113: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009b71b-qlcdngk0a8ie@snom360-00041323230D' of Request 113: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c26700a09c4-mjdp22f7cgks@snom360-0004132328CA' of Request 103: Match Found Feb 14 09:03:13 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c26700a41eb-jvedwbuutm0p@snom360-0004132328B1' of Request 113: Match Found Feb 14 09:03:14 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009e09c-fzaw4537youu@snom360-0004132324D7' of Request 103: Match Found Feb 14 09:03:14 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009cd14-x0w579pzeokk@snom360-000413232740' of Request 112: Match Found Feb 14 09:03:14 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009dbba-dkzcru4xlcpy@snom360-000413232740' of Request 103: Match Found Feb 14 09:03:15 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009dbba-zphjlj7k78dp@snom360-0004132324D7' of Request 107: Match Found Feb 14 09:03:15 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009d6d8-5abtzbzdatse@snom360-000413232740' of Request 107: Match Found Feb 14 09:03:19 NOTICE[4829] chan_sip.c: -- Registration for 'frn6/martin.hetzner@freenet.de' timed out, trying again (Attempt #137) Feb 14 09:03:19 DEBUG[4829] chan_sip.c: Stopping retransmission on '4f6d434b2e05fda3115cba5d27e04455@192.168.4.2' of Request 238: Match Found Feb 14 09:03:19 DEBUG[4829] chan_sip.c: Scheduled a registration timeout for freenet.de id #38759 Feb 14 09:03:20 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009de2b-lbsfzpr7by68@snom360-0004132324D7' of Request 103: Match Found Feb 14 09:03:21 ERROR[4829] chan_sip.c: Got SUBSCRIBE for extensions without hint. Please add hint to 091132391810 in context from-internal Feb 14 09:03:21 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009d949-dav1haeqqbba@snom360-000413232740' of Request 103: Match Found Feb 14 09:03:21 ERROR[4829] chan_sip.c: Got SUBSCRIBE for extensions without hint. Please add hint to 09112342260 in context from-internal Feb 14 09:03:21 ERROR[4829] chan_sip.c: Got SUBSCRIBE for extensions without hint. Please add hint to 091123422621 in context from-internal Feb 14 09:03:21 ERROR[4829] chan_sip.c: Got SUBSCRIBE for extensions without hint. Please add hint to 091123422627 in context from-internal Feb 14 09:03:21 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009bbfd-wokktj7mrx4l@snom360-000413231F0E' of Request 107: Match Found Feb 14 09:03:21 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009bbfd-q5pxchegmjgg@snom360-000413231F0E' of Request 111: Match Found Feb 14 09:03:21 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009be6e-naklb64b76ym@snom360-000413231F0E' of Request 112: Match Found Feb 14 09:03:21 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009be6e-o5jcgqiecot0@snom360-000413231F0E' of Request 106: Match Found Feb 14 09:03:21 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c0df-rwrtbohoop0d@snom360-000413231F0E' of Request 103: Match Found Feb 14 09:03:22 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c350-6hvztm6aoag0@snom360-000413231F0E' of Request 119: Match Found Feb 14 09:03:22 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c5c1-pm968bfxh49k@snom360-000413231F0E' of Request 113: Match Found Feb 14 09:03:22 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c5c1-jcryt9n2ttkr@snom360-000413231F0E' of Request 122: Match Found Feb 14 09:03:22 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c350-hcanmih2ippm@snom360-000413231F0E' of Request 103: Match Found Feb 14 09:03:22 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c832-yvj5qmml1uwj@snom360-000413231F0E' of Request 107: Match Found Feb 14 09:03:22 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009caa3-bdkhy5bv9k5p@snom360-000413231F0E' of Request 107: Match Found Feb 14 09:03:22 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009caa3-3xuesnihcrxt@snom360-000413231F0E' of Request 103: Match Found Feb 14 09:03:22 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009caa3-lmi3nfulst4c@snom360-000413231F0E' of Request 112: Match Found Feb 14 09:03:22 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009cf85-s43kc3cyrwdh@snom360-000413231F0E' of Request 112: Match Found Feb 14 09:03:22 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009caa3-0bljy7giyyxe@snom360-0004132324D2' of Request 103: Match Found Feb 14 09:03:22 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009cf85-k6igouclvyva@snom360-000413231F0E' of Request 105: Match Found Feb 14 09:03:22 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009d1f6-ubmqgh8cbw4c@snom360-000413231F0E' of Request 111: Match Found Feb 14 09:03:23 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c26700a493e-iv19wmkcv7yi@snom360-0004132328B1' of Request 103: Match Found Feb 14 09:03:34 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c350-lzy9b8ucmbfw@snom360-00041323230D' of Request 105: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '2602c04a2c685cc5440e560e6989eb62@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '0c7fcbcb1a0a8eb04887b5cf30c88737@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '6a75ce2a776a8888116caa9636e61ffc@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '6e5cc8742149e78d6f8014d8270ffe91@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '77438de96ff9df1b54dfdc42331d7d12@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '2e0ca31549edd1f908a204e1209f9944@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '10d8670210447d5b1479782f38c96e18@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '6fa5bb0826891da57740d75566476465@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '7d560bdb2d8a89a210b3c77e4c58e0cd@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '611a49bc1e9496f1445c3eab376662a6@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '0a5e470567b0ae427165512963aa9c51@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '79a01b6620c2e8ff47bfc653577a5da8@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '18159acd38daf60f1038872a4c8c402e@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '6c8385ef7ff3e2936ca5883a185edbc3@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '61837d5e4e023a7f08bbe1f970efe4a2@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '45d7131c077b8dc25d3805356c1d619c@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '49ab355b1d343a7d115227b1305699e0@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '7227751d5a76db47799e0a3d7c055ec6@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '381d9f8862255410762848bd0e310c3f@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '75d0f7ad53a26d34615c4aa816691893@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '0a107ea15f27e6dd06c39b28222d830e@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '1397cee57194b3e438b4aa2f58f190e1@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '5f34d97c67ef7b8e771ac8e856a49383@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '71356a6016f0994e7739ff6722561a06@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '34c2c396278a17fb7c3dc0626068466c@192.168.4.2' of Request 102: Match Found Feb 14 09:03:38 DEBUG[4829] chan_sip.c: Stopping retransmission on '650d9a6b69431bf54aeac17f308da8ad@192.168.4.2' of Request 102: Match Found Feb 14 09:03:39 DEBUG[4829] chan_sip.c: Stopping retransmission on '0f7dfc123063af7a5a5fda4275232aab@192.168.4.2' of Request 102: Match Found Feb 14 09:03:39 NOTICE[4829] chan_sip.c: -- Registration for 'frn6/martin.hetzner@freenet.de' timed out, trying again (Attempt #138) Feb 14 09:03:39 DEBUG[4829] chan_sip.c: Stopping retransmission on '4f6d434b2e05fda3115cba5d27e04455@192.168.4.2' of Request 239: Match Found Feb 14 09:03:39 DEBUG[4829] chan_sip.c: Scheduled a registration timeout for freenet.de id #38888 Feb 14 09:03:49 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009cd14-fqpbdd1o0m6b@snom360-0004132324D2' of Request 105: Match Found Feb 14 09:03:52 DEBUG[17619] channel.c: Didn't get a frame from channel: SIP/161-516e Feb 14 09:03:52 DEBUG[17619] channel.c: Bridge stops bridging channels SIP/161-516e and SIP/116-b4ee Feb 14 09:03:52 DEBUG[17619] chan_sip.c: update_call_counter(116) - decrement call limit counter Feb 14 09:03:52 DEBUG[17619] app_dial.c: Exiting with DIALSTATUS=ANSWER. Feb 14 09:03:52 VERBOSE[17619] logger.c: == Spawn extension (macro-dial, s, 10) exited non-zero on 'SIP/161-516e' in macro 'dial' Feb 14 09:03:52 VERBOSE[17619] logger.c: == Spawn extension (macro-exten-vm, s, 7) exited non-zero on 'SIP/161-516e' in macro 'exten-vm' Feb 14 09:03:52 VERBOSE[17619] logger.c: == Spawn extension (from-internal, 116, 1) exited non-zero on 'SIP/161-516e' Feb 14 09:03:52 VERBOSE[17619] logger.c: -- Executing Macro("SIP/161-516e", "hangupcall") in new stack Feb 14 09:03:52 VERBOSE[17619] logger.c: -- Executing ResetCDR("SIP/161-516e", "w") in new stack Feb 14 09:03:52 DEBUG[17619] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. Feb 14 09:03:52 DEBUG[17619] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,$ Feb 14 09:03:52 VERBOSE[17619] logger.c: -- Executing NoCDR("SIP/161-516e", "") in new stack Feb 14 09:03:52 WARNING[17619] cdr.c: CDR on channel 'SIP/161-516e' not posted Feb 14 09:03:52 WARNING[17619] cdr.c: CDR on channel 'SIP/161-516e' lacks end Feb 14 09:03:52 VERBOSE[17619] logger.c: -- Executing DeadAGI("SIP/161-516e", "callback_internal.php.agi") in new stack Feb 14 09:03:52 VERBOSE[17619] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/callback_internal.php.agi Feb 14 09:03:52 DEBUG[4829] chan_sip.c: Stopping retransmission on '047a7c4c78e1f84b30d2c5f3173bdf36@192.168.4.2' of Request 103: Match Found Feb 14 09:03:52 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009e30d-duzaqvfyn5sj@snom360-000413231F12' of Request 115: Match Found Feb 14 09:03:52 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c5c1-pm968bfxh49k@snom360-000413231F0E' of Request 114: Match Found Feb 14 09:03:52 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c832-locpuytqrifi@snom360-000413232742' of Request 113: Match Found Feb 14 09:03:52 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009e57e-7gfpzjbgjcwy@snom360-0004132328D5' of Request 116: Match Found Feb 14 09:03:52 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009b71b-qlcdngk0a8ie@snom360-00041323230D' of Request 114: Match Found Feb 14 09:03:52 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c26700a0000-vnzf21gin77n@snom360-0004132328CA' of Request 114: Match Found Feb 14 09:03:52 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009d6d8-5z107i2tjceh@snom360-0004132324D7' of Request 116: Match Found Feb 14 09:03:52 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009d1f6-9vgl2g8u0b34@snom360-000413232740' of Request 116: Match Found Feb 14 09:03:52 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c267009c0df-1d6jh25idioe@snom360-0004132324D2' of Request 116: Match Found Feb 14 09:03:52 DEBUG[4829] chan_sip.c: Stopping retransmission on '3c26700a41eb-jvedwbuutm0p@snom360-0004132328B1' of Request 114: Match Found Feb 14 09:03:52 DEBUG[17638] manager.c: Manager received command 'login' Feb 14 09:03:52 VERBOSE[17638] logger.c: == Parsing '/etc/asterisk/manager.conf': Feb 14 09:03:52 VERBOSE[17638] logger.c: == Parsing '/etc/asteri$ Feb 14 09:03:52 VERBOSE[17638] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Feb 14 09:03:52 VERBOSE[17638] logger.c: == Parsing '/etc$ Feb 14 09:03:52 WARNING[17638] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf Feb 14 09:03:52 DEBUG[17638] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer Feb 14 09:03:52 DEBUG[17638] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer Feb 14 09:03:52 DEBUG[17638] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 Feb 14 09:03:52 DEBUG[17638] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0 Feb 14 09:03:52 VERBOSE[17638] logger.c: == Manager 'admin' logged on from 127.0.0.1 Feb 14 09:03:52 DEBUG[17638] manager.c: Manager received command 'Logoff' Feb 14 09:03:52 VERBOSE[17619] logger.c: -- AGI Script callback_internal.php.agi completed, returning 0 Feb 14 09:03:52 VERBOSE[17619] logger.c: -- Executing Wait("SIP/161-516e", "5") in new stack Feb 14 09:03:52 VERBOSE[17619] logger.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/161-516e' in macro 'hangupcall' Feb 14 09:03:52 VERBOSE[17619] logger.c: == Spawn extension (from-internal, h, 1) exited non-zero on 'SIP/161-516e' Feb 14 09:03:52 DEBUG[17619] chan_sip.c: update_call_counter(161) - decrement call limit counter Feb 14 09:03:52 VERBOSE[17638] logger.c: == Manager 'admin' logged off from 127.0.0.1