[Mar 26 09:16:39] DEBUG[30344]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9de9100 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[31237]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2ebf9d8 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3069]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e35188 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1782]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=135)
[Mar 26 09:16:39] DEBUG[1783]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bc42f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1051]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x999fc34 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1720]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb158921c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3044]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb110cab4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2787]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=68)
[Mar 26 09:16:39] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2374]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=67)
[Mar 26 09:16:39] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2037]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcf1b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1834]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=141)
[Mar 26 09:16:39] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[32519]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9b06050 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[544]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb18920c8 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[30344]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9de9100 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[31237]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2ebf9d8 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3069]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e35188 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1782]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=135)
[Mar 26 09:16:39] DEBUG[1783]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bc42f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1051]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x999fc34 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1720]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb158921c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3101]: channel.c:1804 ast_settimeout: Scheduling timer at 0 sample intervals
[Mar 26 09:16:39] DEBUG[3101]: channel.c:1804 ast_settimeout: Scheduling timer at 0 sample intervals
[Mar 26 09:16:39] DEBUG[3101]: channel.c:2784 set_format: Set channel SIP/8546-b2805310 to write format alaw
[Mar 26 09:16:39] DEBUG[3101]: app_macro.c:337 _macro_exec: Executed application: Playback
[Mar 26 09:16:39] DEBUG[3101]: pbx.c:1839 pbx_extension_helper: Launching 'Playback'
[Mar 26 09:16:39] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3044]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb110cab4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3101]: channel.c:2784 set_format: Set channel SIP/8546-b2805310 to write format gsm
[Mar 26 09:16:39] DEBUG[3101]: channel.c:1804 ast_settimeout: Scheduling timer at 160 sample intervals
[Mar 26 09:16:39] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2787]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=68)
[Mar 26 09:16:39] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2374]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=67)
[Mar 26 09:16:39] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2037]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcf1b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1834]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=141)
[Mar 26 09:16:39] DEBUG[1835]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99c03fc was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[32519]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9b06050 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[544]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb18920c8 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[30344]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9de9100 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[31237]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2ebf9d8 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3069]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e35188 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1782]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=135)
[Mar 26 09:16:39] DEBUG[1783]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bc42f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1051]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x999fc34 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1720]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb158921c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3044]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb110cab4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2787]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=68)
[Mar 26 09:16:39] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2374]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=67)
[Mar 26 09:16:39] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2037]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcf1b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1834]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=141)
[Mar 26 09:16:39] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[32519]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9b06050 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[544]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb18920c8 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[31237]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2ebf9d8 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[30344]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9de9100 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3069]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e35188 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1783]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bc42f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1782]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=135)
[Mar 26 09:16:39] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1720]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb158921c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1051]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x999fc34 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3044]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb110cab4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2787]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=68)
[Mar 26 09:16:39] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2374]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=67)
[Mar 26 09:16:39] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2037]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcf1b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1834]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=141)
[Mar 26 09:16:39] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[32519]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9b06050 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[544]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb18920c8 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[30344]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9de9100 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[31237]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2ebf9d8 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3069]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e35188 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1782]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=135)
[Mar 26 09:16:39] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1051]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x999fc34 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[1720]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb158921c was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[3044]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb110cab4 was pretty quick last time, waiting for them.
[Mar 26 09:16:39] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: [Mar 26 09:16:42] DEBUG[32519]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9b06050 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[544]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb18920c8 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2168]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=139)
[Mar 26 09:16:42] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[3069]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e35188 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1782]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=135)
[Mar 26 09:16:42] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1051]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x999fc34 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1720]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb158921c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[3030]: rtp.c:728 process_rfc2833: - RTP 2833 Event: 00000000 (len = 4)
[Mar 26 09:16:42] DEBUG[3044]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb110cab4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2787]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=68)
[Mar 26 09:16:42] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2374]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=67)
[Mar 26 09:16:42] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2037]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcf1b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1834]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=141)
[Mar 26 09:16:42] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[32519]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9b06050 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[544]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb18920c8 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2168]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=139)
[Mar 26 09:16:42] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[3069]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e35188 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1782]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=135)
[Mar 26 09:16:42] DEBUG[1051]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x999fc34 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1720]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb158921c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[3030]: rtp.c:728 process_rfc2833: - RTP 2833 Event: 00000000 (len = 4)
[Mar 26 09:16:42] DEBUG[3044]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb110cab4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2787]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=68)
[Mar 26 09:16:42] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2375]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcdb7c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2374]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=67)
[Mar 26 09:16:42] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2037]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcf1b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1834]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=141)
[Mar 26 09:16:42] DEBUG[1835]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99c03fc was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[32519]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9b06050 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[544]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb18920c8 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2168]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=139)
[Mar 26 09:16:42] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[3069]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e35188 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1782]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=135)
[Mar 26 09:16:42] DEBUG[1051]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x999fc34 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1720]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb158921c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[3030]: rtp.c:728 process_rfc2833: - RTP 2833 Event: 00000000 (len = 4)
[Mar 26 09:16:42] DEBUG[3030]: rtp.c:627 send_dtmf: Sending dtmf: 48 (0), at 172.16.0.181
[Mar 26 09:16:42] DEBUG[3044]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb110cab4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2787]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=68)
[Mar 26 09:16:42] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2375]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcdb7c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2374]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=67)
[Mar 26 09:16:42] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2037]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcf1b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1834]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=141)
[Mar 26 09:16:42] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[32519]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9b06050 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[544]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb18920c8 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[2168]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=139)
[Mar 26 09:16:42] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[3069]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e35188 was pretty quick last time, waiting for them.
[Mar 26 09:16:42] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3258]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb111ba9c was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3961]: pbx.c:2435 __ast_pbx_run: Spawn extension (default-agent,8010,21) exited non-zero on 'Local/8010@default-agent-ef5e,2'
[Mar 26 09:17:20] DEBUG[3740]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8010@default-agent-ef5e,1
[Mar 26 09:17:20] DEBUG[3740]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8010@default-agent
[Mar 26 09:17:20] DEBUG[3740]: app_queue.c:1976 ring_one: Trying 'Local/8546@default-agent/n' with metric 2
[Mar 26 09:17:20] DEBUG[3740]: app_queue.c:1826 ring_entry: Local/8546@default-agent/n paused, can't receive call
[Mar 26 09:17:20] DEBUG[3740]: app_queue.c:1976 ring_one: Trying 'Local/8014@default-agent/n' with metric 3
[Mar 26 09:17:20] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8010@default-agent-ef5e,1
[Mar 26 09:17:20] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8010@default-agent-ef5e,1 exists (devicestate)
[Mar 26 09:17:20] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8010@default-agent-ef5e,1 - state 4 (Invalid)
[Mar 26 09:17:20] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8010@default-agent
[Mar 26 09:17:20] DEBUG[2375]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcdb7c was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3740]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable ALLOW_TRANSFER.
[Mar 26 09:17:20] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8010@default-agent-ef5e,1' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Mar 26 09:17:20] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8010@default-agent exists (devicestate)
[Mar 26 09:17:20] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3740]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable ACD_TO_OUTGOING.
[Mar 26 09:17:20] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8010@default-agent - state 2 (In use)
[Mar 26 09:17:20] DEBUG[3740]: channel.c:3299 ast_channel_inherit_variables: Not copying variable QUEUE_PRIO.
[Mar 26 09:17:20] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8010@default-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 26 09:17:20] DEBUG[3740]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable QUEUENAME.
[Mar 26 09:17:20] DEBUG[3740]: channel.c:3299 ast_channel_inherit_variables: Not copying variable AGISTATUS.
[Mar 26 09:17:20] DEBUG[3740]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable INCOMINGLINE.
[Mar 26 09:17:20] DEBUG[3740]: channel.c:3299 ast_channel_inherit_variables: Not copying variable MIXMONITOR_FILENAME.
[Mar 26 09:17:20] DEBUG[3740]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable INCOMING_DNIS.
[Mar 26 09:17:20] DEBUG[2037]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcf1b4 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3341]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=120)
[Mar 26 09:17:20] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3740]: channel.c:3299 ast_channel_inherit_variables: Not copying variable CALLEDTON.
[Mar 26 09:17:20] DEBUG[3948]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1123934 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3342]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bc42f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3785]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb15944cc was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[1835]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99c03fc was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3740]: channel.c:3299 ast_channel_inherit_variables: Not copying variable ANI2.
[Mar 26 09:17:20] DEBUG[3142]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9de9b1c was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3740]: channel.c:3299 ast_channel_inherit_variables: Not copying variable TRANSFERCAPABILITY.
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1839 pbx_extension_helper: Launching 'NoCDR'
[Mar 26 09:17:20] DEBUG[3979]: db.c:198 ast_db_get: Unable to find key '8014/DoNotDisturb' in family 'default'
[Mar 26 09:17:20] DEBUG[3979]: func_db.c:70 function_db_read: DB: default/8014/DoNotDisturb not found in database.
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1688 pbx_substitute_variables_helper_full: Function result is ''
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1839 pbx_extension_helper: Launching 'Set'
[Mar 26 09:17:20] DEBUG[3693]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99a494c was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '0'
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1839 pbx_extension_helper: Launching 'GotoIf'
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:6045 pbx_builtin_gotoif: Not taking any branch
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '7'
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1839 pbx_extension_helper: Launching 'GotoIf'
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1688 pbx_substitute_variables_helper_full: Function result is '1'
[Mar 26 09:17:20] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3080]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=116)
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1688 pbx_substitute_variables_helper_full: Function result is '0'
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1839 pbx_extension_helper: Launching 'Set'
[Mar 26 09:17:20] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1839 pbx_extension_helper: Launching 'GotoIf'
[Mar 26 09:17:20] DEBUG[3979]: pbx.c:1839 pbx_extension_helper: Launching 'Wait'
[Mar 26 09:17:20] DEBUG[3961]: channel.c:1384 ast_softhangup_nolock: Soft-Hanging up channel 'Local/8010@default-agent-ef5e,2'
[Mar 26 09:17:20] DEBUG[3961]: channel.c:1483 ast_hangup: Hanging up channel 'Local/8010@default-agent-ef5e,2'
[Mar 26 09:17:20] DEBUG[3961]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8010@default-agent-ef5e,2
[Mar 26 09:17:20] DEBUG[3961]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8010@default-agent
[Mar 26 09:17:20] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8010@default-agent-ef5e,2
[Mar 26 09:17:20] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8010@default-agent-ef5e,2 exists (devicestate)
[Mar 26 09:17:20] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8010@default-agent-ef5e,2 - state 4 (Invalid)
[Mar 26 09:17:20] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8010@default-agent-ef5e,2' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Mar 26 09:17:20] DEBUG[3170]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=132)
[Mar 26 09:17:20] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3741]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e35ba4 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3740]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=142)
[Mar 26 09:17:20] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8010@default-agent
[Mar 26 09:17:20] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8010@default-agent exists (devicestate)
[Mar 26 09:17:20] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8010@default-agent - state 2 (In use)
[Mar 26 09:17:20] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8010@default-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 26 09:17:20] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3044]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb110c098 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3853]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99fc934 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3361]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb28274dc was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3258]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb111ba9c was pretty quick last time, waiting for them.
[Mar 26 09:17:20] DEBUG[3360]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=118)
[Mar 26 09:17:21] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[2375]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcdb7c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3962]: pbx.c:1839 pbx_extension_helper: Launching 'Congestion'
[Mar 26 09:17:21] DEBUG[3962]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8012@default-agent-2a5e,2
[Mar 26 09:17:21] DEBUG[3962]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8012@default-agent
[Mar 26 09:17:21] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8012@default-agent-2a5e,2
[Mar 26 09:17:21] DEBUG[2037]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcf1b4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8012@default-agent-2a5e,2 exists (devicestate)
[Mar 26 09:17:21] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8012@default-agent-2a5e,2 - state 4 (Invalid)
[Mar 26 09:17:21] DEBUG[3080]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=116)
[Mar 26 09:17:21] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8012@default-agent
[Mar 26 09:17:21] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8012@default-agent exists (devicestate)
[Mar 26 09:17:21] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8012@default-agent - state 2 (In use)
[Mar 26 09:17:21] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8012@default-agent-2a5e,2' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Mar 26 09:17:21] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8012@default-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 26 09:17:21] DEBUG[3948]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1123934 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[1835]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99c03fc was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3341]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=120)
[Mar 26 09:17:21] DEBUG[3342]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bc42f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3142]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9de9b1c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3785]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb15944cc was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3170]: channel.c:1483 ast_hangup: Hanging up channel 'Local/8012@default-agent-2a5e,1'
[Mar 26 09:17:21] DEBUG[3170]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8012@default-agent-2a5e,1
[Mar 26 09:17:21] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8012@default-agent-2a5e,1
[Mar 26 09:17:21] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8012@default-agent-2a5e,1 exists (devicestate)
[Mar 26 09:17:21] DEBUG[3170]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8012@default-agent
[Mar 26 09:17:21] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8012@default-agent-2a5e,1 - state 4 (Invalid)
[Mar 26 09:17:21] DEBUG[3170]: app_queue.c:1976 ring_one: Trying 'Local/8002@default-agent/n' with metric 10
[Mar 26 09:17:21] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8012@default-agent-2a5e,1' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Mar 26 09:17:21] DEBUG[3170]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable ALLOW_TRANSFER.
[Mar 26 09:17:21] DEBUG[3170]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable ACD_TO_OUTGOING.
[Mar 26 09:17:21] DEBUG[3170]: channel.c:3299 ast_channel_inherit_variables: Not copying variable QUEUE_PRIO.
[Mar 26 09:17:21] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8012@default-agent
[Mar 26 09:17:21] DEBUG[3693]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99a494c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:17:21] DEBUG[3170]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable QUEUENAME.
[Mar 26 09:17:21] DEBUG[3170]: channel.c:3299 ast_channel_inherit_variables: Not copying variable AGISTATUS.
[Mar 26 09:17:21] DEBUG[3170]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable INCOMINGLINE.
[Mar 26 09:17:21] DEBUG[3170]: channel.c:3299 ast_channel_inherit_variables: Not copying variable MIXMONITOR_FILENAME.
[Mar 26 09:17:21] DEBUG[3170]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable INCOMING_DNIS.
[Mar 26 09:17:21] DEBUG[3170]: channel.c:3299 ast_channel_inherit_variables: Not copying variable CALLEDTON.
[Mar 26 09:17:21] DEBUG[3170]: channel.c:3299 ast_channel_inherit_variables: Not copying variable ANI2.
[Mar 26 09:17:21] DEBUG[3170]: channel.c:3299 ast_channel_inherit_variables: Not copying variable TRANSFERCAPABILITY.
[Mar 26 09:17:21] DEBUG[3962]: pbx.c:2435 __ast_pbx_run: Spawn extension (default-agent,8012,21) exited non-zero on 'Local/8012@default-agent-2a5e,2'
[Mar 26 09:17:21] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8012@default-agent exists (devicestate)
[Mar 26 09:17:21] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8012@default-agent - state 2 (In use)
[Mar 26 09:17:21] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3962]: channel.c:1384 ast_softhangup_nolock: Soft-Hanging up channel 'Local/8012@default-agent-2a5e,2'
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1839 pbx_extension_helper: Launching 'NoCDR'
[Mar 26 09:17:21] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8012@default-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 26 09:17:21] DEBUG[3962]: channel.c:1483 ast_hangup: Hanging up channel 'Local/8012@default-agent-2a5e,2'
[Mar 26 09:17:21] DEBUG[3980]: db.c:198 ast_db_get: Unable to find key '8002/DoNotDisturb' in family 'default'
[Mar 26 09:17:21] DEBUG[3980]: func_db.c:70 function_db_read: DB: default/8002/DoNotDisturb not found in database.
[Mar 26 09:17:21] DEBUG[3370]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x997ecb4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1688 pbx_substitute_variables_helper_full: Function result is ''
[Mar 26 09:17:21] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1839 pbx_extension_helper: Launching 'Set'
[Mar 26 09:17:21] DEBUG[3962]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8012@default-agent-2a5e,2
[Mar 26 09:17:21] DEBUG[3962]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8012@default-agent
[Mar 26 09:17:21] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8012@default-agent-2a5e,2
[Mar 26 09:17:21] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8012@default-agent-2a5e,2 exists (devicestate)
[Mar 26 09:17:21] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8012@default-agent-2a5e,2 - state 4 (Invalid)
[Mar 26 09:17:21] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8012@default-agent-2a5e,2' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Mar 26 09:17:21] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8012@default-agent
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '0'
[Mar 26 09:17:21] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8012@default-agent exists (devicestate)
[Mar 26 09:17:21] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8012@default-agent - state 2 (In use)
[Mar 26 09:17:21] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8012@default-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1839 pbx_extension_helper: Launching 'GotoIf'
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:6045 pbx_builtin_gotoif: Not taking any branch
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '7'
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1839 pbx_extension_helper: Launching 'GotoIf'
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1688 pbx_substitute_variables_helper_full: Function result is '1'
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1688 pbx_substitute_variables_helper_full: Function result is '0'
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1839 pbx_extension_helper: Launching 'Set'
[Mar 26 09:17:21] DEBUG[3740]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=142)
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1839 pbx_extension_helper: Launching 'GotoIf'
[Mar 26 09:17:21] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3980]: pbx.c:1839 pbx_extension_helper: Launching 'Wait'
[Mar 26 09:17:21] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[30254]: manager.c:2107 process_message: Manager received command 'ExtensionState'
[Mar 26 09:17:21] DEBUG[30254]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for SIP - 8030
[Mar 26 09:17:21] DEBUG[3171]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9b06a6c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[30254]: chan_sip.c:15920 sip_devicestate: Checking device state for peer 8030
[Mar 26 09:17:21] DEBUG[3170]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=132)
[Mar 26 09:17:21] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3044]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb110c098 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3853]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99fc934 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3360]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=118)
[Mar 26 09:17:21] DEBUG[3258]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb111ba9c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[2375]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcdb7c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3080]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=116)
[Mar 26 09:17:21] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[2037]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcf1b4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[1835]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99c03fc was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3948]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1123934 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3341]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=120)
[Mar 26 09:17:21] DEBUG[3342]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bc42f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3142]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9de9b1c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3785]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb15944cc was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:17:21] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:17:21] DEBUG[3370]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x997ecb4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3740]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=142)
[Mar 26 09:17:21] DEBUG[3741]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e35ba4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3170]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=132)
[Mar 26 09:17:21] DEBUG[3171]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9b06a6c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3044]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb110c098 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3853]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99fc934 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3360]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=118)
[Mar 26 09:17:21] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3258]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb111ba9c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[2375]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcdb7c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3080]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=116)
[Mar 26 09:17:21] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[2037]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcf1b4 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[1835]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99c03fc was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3948]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1123934 was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3341]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=120)
[Mar 26 09:17:21] DEBUG[3142]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9de9b1c was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[3785]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb15944cc was pretty quick last time, waiting for them.
[Mar 26 09:17:21] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1835]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99c03fc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3948]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1123934 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3142]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9de9b1c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3785]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb15944cc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:17:46] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:17:46] DEBUG[3370]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x997ecb4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[4206]: audiohook.c:252 audiohook_read_frame_both: Failed to get 160 samples from write factory 0xb19bcf74
[Mar 26 09:17:46] DEBUG[3170]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=132)
[Mar 26 09:17:46] DEBUG[3171]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9b06a6c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3741]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e35ba4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3740]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=142)
[Mar 26 09:17:46] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3044]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb110cab4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3852]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=57)
[Mar 26 09:17:46] DEBUG[4300]: pbx.c:1839 pbx_extension_helper: Launching 'Congestion'
[Mar 26 09:17:46] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[4300]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8006@default-agent-f405,2
[Mar 26 09:17:46] DEBUG[3170]: channel.c:1483 ast_hangup: Hanging up channel 'Local/8006@default-agent-f405,1'
[Mar 26 09:17:46] DEBUG[4300]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8006@default-agent
[Mar 26 09:17:46] DEBUG[3170]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8006@default-agent-f405,1
[Mar 26 09:17:46] DEBUG[3170]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8006@default-agent
[Mar 26 09:17:46] DEBUG[3170]: app_queue.c:1976 ring_one: Trying 'Local/8017@default-agent/n' with metric 13
[Mar 26 09:17:46] DEBUG[3258]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb111ba9c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8006@default-agent-f405,2
[Mar 26 09:17:46] DEBUG[4300]: pbx.c:2435 __ast_pbx_run: Spawn extension (default-agent,8006,21) exited non-zero on 'Local/8006@default-agent-f405,2'
[Mar 26 09:17:46] DEBUG[4300]: channel.c:1384 ast_softhangup_nolock: Soft-Hanging up channel 'Local/8006@default-agent-f405,2'
[Mar 26 09:17:46] DEBUG[4300]: channel.c:1483 ast_hangup: Hanging up channel 'Local/8006@default-agent-f405,2'
[Mar 26 09:17:46] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8006@default-agent-f405,2 exists (devicestate)
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8006@default-agent-f405,2 - state 4 (Invalid)
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8006@default-agent
[Mar 26 09:17:46] DEBUG[2037]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9bce798 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8006@default-agent-f405,2' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Mar 26 09:17:46] DEBUG[3080]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=116)
[Mar 26 09:17:46] DEBUG[3170]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable ALLOW_TRANSFER.
[Mar 26 09:17:46] DEBUG[3361]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb28274dc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3170]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable ACD_TO_OUTGOING.
[Mar 26 09:17:46] DEBUG[2375]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcdb7c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3170]: channel.c:3299 ast_channel_inherit_variables: Not copying variable QUEUE_PRIO.
[Mar 26 09:17:46] DEBUG[3170]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable QUEUENAME.
[Mar 26 09:17:46] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8006@default-agent exists (devicestate)
[Mar 26 09:17:46] DEBUG[3360]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=118)
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8006@default-agent - state 2 (In use)
[Mar 26 09:17:46] DEBUG[4300]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8006@default-agent-f405,2
[Mar 26 09:17:46] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8006@default-agent-f405,1
[Mar 26 09:17:46] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8006@default-agent-f405,1 exists (devicestate)
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8006@default-agent-f405,1 - state 4 (Invalid)
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8006@default-agent
[Mar 26 09:17:46] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8006@default-agent exists (devicestate)
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8006@default-agent - state 2 (In use)
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8006@default-agent-f405,2
[Mar 26 09:17:46] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8006@default-agent-f405,2 exists (devicestate)
[Mar 26 09:17:46] DEBUG[3341]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=120)
[Mar 26 09:17:46] DEBUG[3170]: channel.c:3299 ast_channel_inherit_variables: Not copying variable AGISTATUS.
[Mar 26 09:17:46] DEBUG[3170]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable INCOMINGLINE.
[Mar 26 09:17:46] DEBUG[3170]: channel.c:3299 ast_channel_inherit_variables: Not copying variable MIXMONITOR_FILENAME.
[Mar 26 09:17:46] DEBUG[3170]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable INCOMING_DNIS.
[Mar 26 09:17:46] DEBUG[3170]: channel.c:3299 ast_channel_inherit_variables: Not copying variable CALLEDTON.
[Mar 26 09:17:46] DEBUG[3170]: channel.c:3299 ast_channel_inherit_variables: Not copying variable ANI2.
[Mar 26 09:17:46] DEBUG[3170]: channel.c:3299 ast_channel_inherit_variables: Not copying variable TRANSFERCAPABILITY.
[Mar 26 09:17:46] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8006@default-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 26 09:17:46] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8006@default-agent-f405,1' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Mar 26 09:17:46] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8006@default-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 26 09:17:46] DEBUG[3342]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bc42f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:17:46] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3142]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9de9b1c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3785]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb15944cc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8006@default-agent-f405,2 - state 4 (Invalid)
[Mar 26 09:17:46] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8006@default-agent-f405,2' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Mar 26 09:17:46] DEBUG[1835]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99c03fc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3948]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1123934 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1839 pbx_extension_helper: Launching 'NoCDR'
[Mar 26 09:17:46] DEBUG[4310]: db.c:198 ast_db_get: Unable to find key '8017/DoNotDisturb' in family 'default'
[Mar 26 09:17:46] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:17:46] DEBUG[4310]: func_db.c:70 function_db_read: DB: default/8017/DoNotDisturb not found in database.
[Mar 26 09:17:46] DEBUG[4300]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8006@default-agent
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8006@default-agent
[Mar 26 09:17:46] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8006@default-agent exists (devicestate)
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1688 pbx_substitute_variables_helper_full: Function result is ''
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8006@default-agent - state 2 (In use)
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1839 pbx_extension_helper: Launching 'Set'
[Mar 26 09:17:46] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8006@default-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 26 09:17:46] DEBUG[4206]: audiohook.c:252 audiohook_read_frame_both: Failed to get 160 samples from write factory 0xb19bcf74
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '0'
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1839 pbx_extension_helper: Launching 'GotoIf'
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:6045 pbx_builtin_gotoif: Not taking any branch
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '7'
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1839 pbx_extension_helper: Launching 'GotoIf'
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1688 pbx_substitute_variables_helper_full: Function result is '0'
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1688 pbx_substitute_variables_helper_full: Function result is '1'
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar 26 09:17:46] DEBUG[3170]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=132)
[Mar 26 09:17:46] DEBUG[3171]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9b06a6c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3741]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e35ba4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1839 pbx_extension_helper: Launching 'Set'
[Mar 26 09:17:46] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3740]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=142)
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1839 pbx_extension_helper: Launching 'GotoIf'
[Mar 26 09:17:46] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[4310]: pbx.c:1839 pbx_extension_helper: Launching 'Wait'
[Mar 26 09:17:46] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3044]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb110cab4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3853]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99fc934 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3852]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=57)
[Mar 26 09:17:46] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3361]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb28274dc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3258]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb111ba9c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3360]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=118)
[Mar 26 09:17:46] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2037]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9bce798 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2375]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcdb7c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3080]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=116)
[Mar 26 09:17:46] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1835]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99c03fc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3342]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bc42f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3948]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1123934 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3341]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=120)
[Mar 26 09:17:46] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3142]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9de9b1c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3785]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb15944cc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3693]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99a494c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:17:46] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:17:46] DEBUG[4206]: audiohook.c:252 audiohook_read_frame_both: Failed to get 160 samples from write factory 0xb19bcf74
[Mar 26 09:17:46] DEBUG[3740]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=142)
[Mar 26 09:17:46] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3171]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9b06a6c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3170]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=132)
[Mar 26 09:17:46] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3044]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb110cab4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3852]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=57)
[Mar 26 09:17:46] DEBUG[3853]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99fc934 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3360]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=118)
[Mar 26 09:17:46] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3258]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb111ba9c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2037]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9bce798 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3080]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=116)
[Mar 26 09:17:46] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2375]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcdb7c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3341]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=120)
[Mar 26 09:17:46] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1835]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99c03fc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3948]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1123934 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3142]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9de9b1c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3785]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb15944cc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3693]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99a494c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:17:46] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:17:46] DEBUG[4206]: audiohook.c:252 audiohook_read_frame_both: Failed to get 160 samples from write factory 0xb19bcf74
[Mar 26 09:17:46] DEBUG[3740]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=142)
[Mar 26 09:17:46] DEBUG[3170]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=132)
[Mar 26 09:17:46] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3171]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9b06a6c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x97f7a4c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[894]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d9d1f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3852]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=57)
[Mar 26 09:17:46] DEBUG[3853]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99fc934 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3044]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb110cab4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1625]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f07b0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[4301]: pbx.c:1839 pbx_extension_helper: Launching 'Congestion'
[Mar 26 09:17:46] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2788]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9d5db14 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3360]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=118)
[Mar 26 09:17:46] DEBUG[3258]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb111ba9c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[4301]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8017@default-agent-c667,2
[Mar 26 09:17:46] DEBUG[3360]: channel.c:1483 ast_hangup: Hanging up channel 'Local/8017@default-agent-c667,1'
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8017@default-agent-c667,2
[Mar 26 09:17:46] DEBUG[4301]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8017@default-agent
[Mar 26 09:17:46] DEBUG[3360]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8017@default-agent-c667,1
[Mar 26 09:17:46] DEBUG[4301]: pbx.c:2435 __ast_pbx_run: Spawn extension (default-agent,8017,21) exited non-zero on 'Local/8017@default-agent-c667,2'
[Mar 26 09:17:46] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8017@default-agent-c667,2 exists (devicestate)
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8017@default-agent-c667,2 - state 4 (Invalid)
[Mar 26 09:17:46] DEBUG[3080]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=116)
[Mar 26 09:17:46] DEBUG[3031]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x91e60a0 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2375]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bcdb7c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2037]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9bce798 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1746]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ad3ac was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[2010]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1d0100c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[1835]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99c03fc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3341]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=120)
[Mar 26 09:17:46] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3342]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bc42f4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3948]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1123934 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3142]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9de9b1c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[811]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e198bc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3785]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb15944cc was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3360]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8017@default-agent
[Mar 26 09:17:46] DEBUG[4301]: channel.c:1384 ast_softhangup_nolock: Soft-Hanging up channel 'Local/8017@default-agent-c667,2'
[Mar 26 09:17:46] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:17:46] DEBUG[3693]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99a494c was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8017@default-agent-c667,2' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Mar 26 09:17:46] DEBUG[3370]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x997ecb4 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:17:46] DEBUG[3360]: app_queue.c:1976 ring_one: Trying 'Local/8030@default-agent/n' with metric 14
[Mar 26 09:17:46] DEBUG[4301]: channel.c:1483 ast_hangup: Hanging up channel 'Local/8017@default-agent-c667,2'
[Mar 26 09:17:46] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8017@default-agent
[Mar 26 09:17:46] DEBUG[3360]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable ALLOW_TRANSFER.
[Mar 26 09:17:46] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8017@default-agent exists (devicestate)
[Mar 26 09:17:46] DEBUG[3360]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable ACD_TO_OUTGOING.
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8017@default-agent - state 2 (In use)
[Mar 26 09:17:46] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8017@default-agent-c667,1
[Mar 26 09:17:48] DEBUG[3741]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e35ba4 was pretty quick last time, waiting for them.
[Mar 26 09:17:48] DEBUG[684]: audiohook.c:205 audiohook_read_frame_both: Write fact
[Mar 26 09:18:41] DEBUG[2375]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9bcd160 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[2010]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d005f0 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[1746]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98ac990 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[684]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f7030 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[894]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d9c7d8 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:18:41] DEBUG[3693]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99a494c was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5414]: audiohook.c:252 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x9b4ac24
[Mar 26 09:18:41] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:18:41] DEBUG[3370]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x997ecb4 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[4206]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb19bcf74 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5070]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9980b84 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5069]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=164)
[Mar 26 09:18:41] DEBUG[5289]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb19b8f88 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3741]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e35ba4 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3740]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=142)
[Mar 26 09:18:41] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[811]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e18ea0 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[2788]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9d5d0f8 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3258]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb111b080 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[4361]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99893ac was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5052]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb197fe8c was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3853]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99fc934 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[31336]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=13)
[Mar 26 09:18:41] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5180]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb19fcbc8 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3080]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=116)
[Mar 26 09:18:41] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3341]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=120)
[Mar 26 09:18:41] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[2375]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9bcd160 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[1746]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98ac990 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[2010]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d005f0 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[1932]: rtp.c:880 ast_rtcp_read: Got RTCP report of 76 bytes
[Mar 26 09:18:41] DEBUG[684]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f7030 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[894]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d9c7d8 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:18:41] DEBUG[3693]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99a494c was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5414]: audiohook.c:252 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x9b4ac24
[Mar 26 09:18:41] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:18:41] DEBUG[3370]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x997ecb4 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[4206]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb19bcf74 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5069]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=164)
[Mar 26 09:18:41] DEBUG[5070]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9980b84 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5289]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb19b8f88 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3741]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e35ba4 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5281]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb111801c was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3171]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9b06a6c was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3740]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=142)
[Mar 26 09:18:41] DEBUG[811]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e18ea0 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[2788]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9d5d0f8 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3258]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb111b080 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[4361]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99893ac was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5052]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb197fe8c was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5463]: pbx.c:1839 pbx_extension_helper: Launching 'Congestion'
[Mar 26 09:18:41] DEBUG[3080]: channel.c:1483 ast_hangup: Hanging up channel 'Local/8030@default-agent-fb6a,1'
[Mar 26 09:18:41] DEBUG[3853]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99fc934 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3080]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8030@default-agent-fb6a,1
[Mar 26 09:18:41] DEBUG[3080]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8030@default-agent
[Mar 26 09:18:41] DEBUG[3080]: app_queue.c:1976 ring_one: Trying 'Local/8020@default-agent/n' with metric 1000
[Mar 26 09:18:41] DEBUG[5463]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8030@default-agent-fb6a,2
[Mar 26 09:18:41] DEBUG[5463]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8030@default-agent
[Mar 26 09:18:41] DEBUG[3080]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable ALLOW_TRANSFER.
[Mar 26 09:18:41] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8030@default-agent-fb6a,1
[Mar 26 09:18:41] DEBUG[5463]: pbx.c:2435 __ast_pbx_run: Spawn extension (default-agent,8030,21) exited non-zero on 'Local/8030@default-agent-fb6a,2'
[Mar 26 09:18:41] DEBUG[3080]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable ACD_TO_OUTGOING.
[Mar 26 09:18:41] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8030@default-agent-fb6a,1 exists (devicestate)
[Mar 26 09:18:41] DEBUG[5463]: channel.c:1384 ast_softhangup_nolock: Soft-Hanging up channel 'Local/8030@default-agent-fb6a,2'
[Mar 26 09:18:41] DEBUG[3080]: channel.c:3299 ast_channel_inherit_variables: Not copying variable QUEUE_PRIO.
[Mar 26 09:18:41] DEBUG[5463]: channel.c:1483 ast_hangup: Hanging up channel 'Local/8030@default-agent-fb6a,2'
[Mar 26 09:18:41] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8030@default-agent-fb6a,1 - state 4 (Invalid)
[Mar 26 09:18:41] DEBUG[3080]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable QUEUENAME.
[Mar 26 09:18:41] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8030@default-agent
[Mar 26 09:18:41] DEBUG[3080]: channel.c:3299 ast_channel_inherit_variables: Not copying variable AGISTATUS.
[Mar 26 09:18:41] DEBUG[5463]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8030@default-agent-fb6a,2
[Mar 26 09:18:41] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8030@default-agent-fb6a,1' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Mar 26 09:18:41] DEBUG[3080]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable INCOMINGLINE.
[Mar 26 09:18:41] DEBUG[3080]: channel.c:3299 ast_channel_inherit_variables: Not copying variable MIXMONITOR_FILENAME.
[Mar 26 09:18:41] DEBUG[3080]: channel.c:3294 ast_channel_inherit_variables: Copying hard-transferable variable INCOMING_DNIS.
[Mar 26 09:18:41] DEBUG[3080]: channel.c:3299 ast_channel_inherit_variables: Not copying variable CALLEDTON.
[Mar 26 09:18:41] DEBUG[31336]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=13)
[Mar 26 09:18:41] DEBUG[5463]: devicestate.c:304 __ast_device_state_changed_literal: Notification of state change to be queued on device/channel Local/8030@default-agent
[Mar 26 09:18:41] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8030@default-agent exists (devicestate)
[Mar 26 09:18:41] DEBUG[3080]: channel.c:3299 ast_channel_inherit_variables: Not copying variable ANI2.
[Mar 26 09:18:41] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8030@default-agent - state 2 (In use)
[Mar 26 09:18:41] DEBUG[3080]: channel.c:3299 ast_channel_inherit_variables: Not copying variable TRANSFERCAPABILITY.
[Mar 26 09:18:41] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5180]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb19fcbc8 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8030@default-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 26 09:18:41] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8030@default-agent-fb6a,2
[Mar 26 09:18:41] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8030@default-agent-fb6a,2 exists (devicestate)
[Mar 26 09:18:41] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8030@default-agent-fb6a,2 - state 4 (Invalid)
[Mar 26 09:18:41] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8030@default-agent
[Mar 26 09:18:41] DEBUG[3080]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=116)
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1839 pbx_extension_helper: Launching 'NoCDR'
[Mar 26 09:18:41] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8030@default-agent exists (devicestate)
[Mar 26 09:18:41] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8030@default-agent - state 2 (In use)
[Mar 26 09:18:41] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8030@default-agent-fb6a,2
[Mar 26 09:18:41] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8030@default-agent-fb6a,2 exists (devicestate)
[Mar 26 09:18:41] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8030@default-agent-fb6a,2 - state 4 (Invalid)
[Mar 26 09:18:41] DEBUG[13755]: devicestate.c:161 ast_device_state: No provider found, checking channel drivers for Local - 8030@default-agent
[Mar 26 09:18:41] DEBUG[13755]: chan_local.c:145 local_devicestate: Checking if extension 8030@default-agent exists (devicestate)
[Mar 26 09:18:41] DEBUG[13755]: devicestate.c:287 do_state_change: Changing state for Local/8030@default-agent - state 2 (In use)
[Mar 26 09:18:41] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8030@default-agent-fb6a,2' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Mar 26 09:18:41] DEBUG[5472]: db.c:198 ast_db_get: Unable to find key '8020/DoNotDisturb' in family 'default'
[Mar 26 09:18:41] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5472]: func_db.c:70 function_db_read: DB: default/8020/DoNotDisturb not found in database.
[Mar 26 09:18:41] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8030@default-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1688 pbx_substitute_variables_helper_full: Function result is ''
[Mar 26 09:18:41] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8030@default-agent-fb6a,2' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1839 pbx_extension_helper: Launching 'Set'
[Mar 26 09:18:41] DEBUG[13785]: app_queue.c:665 handle_statechange: Device 'Local/8030@default-agent' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Mar 26 09:18:41] DEBUG[3341]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=120)
[Mar 26 09:18:41] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '0'
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1839 pbx_extension_helper: Launching 'GotoIf'
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:6045 pbx_builtin_gotoif: Not taking any branch
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '7'
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1839 pbx_extension_helper: Launching 'GotoIf'
[Mar 26 09:18:41] DEBUG[2375]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9bcd160 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1688 pbx_substitute_variables_helper_full: Function result is '1'
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1688 pbx_substitute_variables_helper_full: Function result is '0'
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1839 pbx_extension_helper: Launching 'Set'
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1756 pbx_substitute_variables_helper_full: Expression result is '1'
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1839 pbx_extension_helper: Launching 'GotoIf'
[Mar 26 09:18:41] DEBUG[2010]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d005f0 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[1746]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98ac990 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5472]: pbx.c:1839 pbx_extension_helper: Launching 'Wait'
[Mar 26 09:18:41] DEBUG[684]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f7030 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[894]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d9c7d8 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:18:41] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[5414]: audiohook.c:252 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x9b4ac24
[Mar 26 09:18:41] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:18:41] DEBUG[3370]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x997ecb4 was pretty quick last time, waiting for them.
[Mar 26 09:18:41] DEBUG[4206]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb19bcf74 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5414]: audiohook.c:252 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x9b4ac24
[Mar 26 09:18:43] DEBUG[3370]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x997ecb4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:18:43] DEBUG[4206]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb19bcf74 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5069]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=164)
[Mar 26 09:18:43] DEBUG[5070]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9980b84 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5289]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb19b8f88 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3741]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e35ba4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3171]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9b06a6c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5281]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb111801c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3740]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=142)
[Mar 26 09:18:43] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[811]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e18ea0 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[2788]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9d5d0f8 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3258]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb111b080 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5052]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb197fe8c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[4361]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99893ac was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3853]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99fc934 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[31336]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=13)
[Mar 26 09:18:43] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5180]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb19fcbc8 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3080]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=116)
[Mar 26 09:18:43] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3341]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=120)
[Mar 26 09:18:43] DEBUG[3342]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bc42f4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[2375]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9bcd160 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[1746]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98ac990 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[2010]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d005f0 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[684]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f7030 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[894]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d9c7d8 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:18:43] DEBUG[3693]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99a494c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[849]: rtp.c:880 ast_rtcp_read: Got RTCP report of 76 bytes
[Mar 26 09:18:43] DEBUG[5414]: audiohook.c:252 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x9b4ac24
[Mar 26 09:18:43] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:18:43] DEBUG[3370]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x997ecb4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[4206]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb19bcf74 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5069]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=164)
[Mar 26 09:18:43] DEBUG[5070]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9980b84 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5289]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb19b8f88 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3740]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=142)
[Mar 26 09:18:43] DEBUG[3741]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e35ba4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5281]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1117600 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3171]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9b06a6c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[811]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e18ea0 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3258]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb111b080 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[2788]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9d5d0f8 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5052]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb197fe8c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[4361]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99893ac was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3853]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99fc934 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[31336]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=13)
[Mar 26 09:18:43] DEBUG[30425]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98322c0 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5180]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb19fcbc8 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[31390]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb2801850 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[409]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d22ac0 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3081]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9ce457c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3080]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=116)
[Mar 26 09:18:43] DEBUG[32624]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb1638194 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3342]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9bc42f4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3341]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=120)
[Mar 26 09:18:43] DEBUG[31665]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e1de5c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[2375]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9bcd160 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3257]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1591260 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[1746]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x98ac990 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[2010]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d005f0 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[684]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x97f7030 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[894]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1d9c7d8 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3690]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=105)
[Mar 26 09:18:43] DEBUG[3102]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x999cf18 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3693]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99a494c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5414]: audiohook.c:252 audiohook_read_frame_both: Failed to get 160 samples from write factory 0x9b4ac24
[Mar 26 09:18:43] DEBUG[3369]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=128)
[Mar 26 09:18:43] DEBUG[3370]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x997ecb4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[4206]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb19bcf74 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5069]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=164)
[Mar 26 09:18:43] DEBUG[5070]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9980b84 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5289]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb19b8f88 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3740]: channel.c:2318 ast_internal_timing_enabled: Internal timing is disabled (option_internal_timing=0 chan->timingfd=142)
[Mar 26 09:18:43] DEBUG[3741]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9e35ba4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5281]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb1117600 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[1664]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99497f4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3171]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x9b06a6c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[2355]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb4bce7b4 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[811]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9e18ea0 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[1059]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9821138 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3258]: audiohook.c:212 audiohook_read_frame_both: Read factory 0xb111b080 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[2788]: audiohook.c:212 audiohook_read_frame_both: Read factory 0x9d5d0f8 was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[5052]: audiohook.c:205 audiohook_read_frame_both: Write factory 0xb197fe8c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[4361]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99893ac was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[32434]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x98ebd4c was pretty quick last time, waiting for them.
[Mar 26 09:18:43] DEBUG[3853]: audiohook.c:205 audiohook_read_frame_both: Write factory 0x99fc934 was pretty quick last time, waiting for them.