<html>
 <body>
  <div style="font-family: Verdana, Arial, Helvetica, Sans-Serif;">
   <table bgcolor="#f9f3c9" width="100%" cellpadding="8" style="border: 1px #c9c399 solid;">
    <tr>
     <td>
      This is an automatically generated e-mail. To reply, visit:
      <a href="https://reviewboard.asterisk.org/r/1255/">https://reviewboard.asterisk.org/r/1255/</a>
     </td>
    </tr>
   </table>
   <br />








<blockquote style="margin-left: 1em; border-left: 2px solid #d0d0d0; padding-left: 10px;">
 <p style="margin-top: 0;">On July 6th, 2011, 10:20 a.m., <b>David Vossel</b> wrote:</p>
 <blockquote style="margin-left: 1em; border-left: 2px solid #d0d0d0; padding-left: 10px;">
  



<table width="100%" border="0" bgcolor="white" style="border: 1px solid #C0C0C0; border-collapse: collapse; margin: 2px padding: 2px;">
 <thead>
  <tr>
   <th colspan="4" bgcolor="#F0F0F0" style="border-bottom: 1px solid #C0C0C0; font-size: 9pt; padding: 4px 8px; text-align: left;">
    <a href="https://reviewboard.asterisk.org/r/1255/diff/2/?file=16826#file16826line174" style="color: black; font-weight: bold; text-decoration: underline;">branches/1.8/res/res_timing_timerfd.c</a>
    <span style="font-weight: normal;">

     (Diff revision 2)

    </span>
   </th>
  </tr>
 </thead>

 <tbody style="background-color: #e4d9cb; padding: 4px 8px; text-align: center;">
  <tr>

   <td colspan="4"><pre style="font-size: 8pt; line-height: 140%; margin: 0; ">static int timerfd_timer_set_rate(int handle, unsigned int rate)</pre></td>

  </tr>
 </tbody>




 
 



 <tbody>

  <tr>
    <th bgcolor="#b1ebb0" style="border-right: 1px solid #C0C0C0;" align="right"><font size="2"></font></th>
    <td bgcolor="#c5ffc4" width="50%"><pre style="font-size: 8pt; line-height: 140%; margin: 0; "></pre></td>
    <th bgcolor="#b1ebb0" style="border-left: 1px solid #C0C0C0; border-right: 1px solid #C0C0C0;" align="right"><font size="2">174</font></th>
    <td bgcolor="#c5ffc4" width="50%"><pre style="font-size: 8pt; line-height: 140%; margin: 0; ">        <span class="k">if</span> <span class="p">(</span><span class="n">our_timer</span><span class="o">-&gt;</span><span class="n">saved_timer</span><span class="p">.</span><span class="n">it_value</span><span class="p">.</span><span class="n">tv_nsec</span> <span class="o">==</span> <span class="mi">0L</span><span class="p">)</span> <span class="p">{</span></pre></td>
  </tr>

  <tr>
    <th bgcolor="#b1ebb0" style="border-right: 1px solid #C0C0C0;" align="right"><font size="2"></font></th>
    <td bgcolor="#c5ffc4" width="50%"><pre style="font-size: 8pt; line-height: 140%; margin: 0; "></pre></td>
    <th bgcolor="#b1ebb0" style="border-left: 1px solid #C0C0C0; border-right: 1px solid #C0C0C0;" align="right"><font size="2">175</font></th>
    <td bgcolor="#c5ffc4" width="50%"><pre style="font-size: 8pt; line-height: 140%; margin: 0; ">                <span class="n">ast_log</span><span class="p">(</span><span class="n">LOG_WARNING</span><span class="p">,</span> <span class="s">&quot;Reading attempt on idle timerfd. This would have caused a deadlock.</span><span class="se">\n</span><span class="s">&quot;</span><span class="p">);</span></pre></td>
  </tr>

  <tr>
    <th bgcolor="#b1ebb0" style="border-right: 1px solid #C0C0C0;" align="right"><font size="2"></font></th>
    <td bgcolor="#c5ffc4" width="50%"><pre style="font-size: 8pt; line-height: 140%; margin: 0; "></pre></td>
    <th bgcolor="#b1ebb0" style="border-left: 1px solid #C0C0C0; border-right: 1px solid #C0C0C0;" align="right"><font size="2">176</font></th>
    <td bgcolor="#c5ffc4" width="50%"><pre style="font-size: 8pt; line-height: 140%; margin: 0; ">                <span class="k">return</span><span class="p">;</span></pre></td>
  </tr>

  <tr>
    <th bgcolor="#b1ebb0" style="border-right: 1px solid #C0C0C0;" align="right"><font size="2"></font></th>
    <td bgcolor="#c5ffc4" width="50%"><pre style="font-size: 8pt; line-height: 140%; margin: 0; "></pre></td>
    <th bgcolor="#b1ebb0" style="border-left: 1px solid #C0C0C0; border-right: 1px solid #C0C0C0;" align="right"><font size="2">177</font></th>
    <td bgcolor="#c5ffc4" width="50%"><pre style="font-size: 8pt; line-height: 140%; margin: 0; ">        <span class="p">}</span></pre></td>
  </tr>

  <tr>
    <th bgcolor="#b1ebb0" style="border-right: 1px solid #C0C0C0;" align="right"><font size="2"></font></th>
    <td bgcolor="#c5ffc4" width="50%"><pre style="font-size: 8pt; line-height: 140%; margin: 0; "></pre></td>
    <th bgcolor="#b1ebb0" style="border-left: 1px solid #C0C0C0; border-right: 1px solid #C0C0C0;" align="right"><font size="2">178</font></th>
    <td bgcolor="#c5ffc4" width="50%"><pre style="font-size: 8pt; line-height: 140%; margin: 0; "></pre></td>
  </tr>

 </tbody>

</table>

  <pre style="white-space: pre-wrap; white-space: -moz-pre-wrap; white-space: -pre-wrap; white-space: -o-pre-wrap; word-wrap: break-word;">I had to revert the patch from 1.8 and trunk.  This statement right hear is causing some serious performance problems.  See jrose&#39;s comment.

If we comment out this line, everything works fine for him.</pre>
 </blockquote>



 <p>On July 6th, 2011, 10:33 a.m., <b>David Vossel</b> wrote:</p>
 <blockquote style="margin-left: 1em; border-left: 2px solid #d0d0d0; padding-left: 10px;">
  <pre style="white-space: pre-wrap; white-space: -moz-pre-wrap; white-space: -pre-wrap; white-space: -o-pre-wrap; word-wrap: break-word;">This same issue was reported here. https://issues.asterisk.org/jira/browse/ASTERISK-17867</pre>
 </blockquote>





 <p>On July 6th, 2011, 10:44 a.m., <b>kobaz</b> wrote:</p>
 <blockquote style="margin-left: 1em; border-left: 2px solid #d0d0d0; padding-left: 10px;">
  <pre style="white-space: pre-wrap; white-space: -moz-pre-wrap; white-space: -pre-wrap; white-space: -o-pre-wrap; word-wrap: break-word;">So, the whole patch was reverted.  Is your vote to have the same code fix but minus the debugging?  I&#39;ve also heard from several people that the fix works with the debugging removed.</pre>
 </blockquote>





 <p>On July 6th, 2011, 11:04 a.m., <b>David Vossel</b> wrote:</p>
 <blockquote style="margin-left: 1em; border-left: 2px solid #d0d0d0; padding-left: 10px;">
  <pre style="white-space: pre-wrap; white-space: -moz-pre-wrap; white-space: -pre-wrap; white-space: -o-pre-wrap; word-wrap: break-word;">We tried taking out the debug statement in this if block, but it still caused performance issues.  Things did not work well until we completely took out that if statement.</pre>
 </blockquote>





 <p>On July 6th, 2011, 11:06 a.m., <b>jrose</b> wrote:</p>
 <blockquote style="margin-left: 1em; border-left: 2px solid #d0d0d0; padding-left: 10px;">
  <pre style="white-space: pre-wrap; white-space: -moz-pre-wrap; white-space: -pre-wrap; white-space: -o-pre-wrap; word-wrap: break-word;">Actually, the if statement was fine as long as you didn&#39;t include the return.  It&#39;s running through the whole loop until the call is answered that causes the problem.</pre>
 </blockquote>





 <p>On July 6th, 2011, 11:11 a.m., <b>jrose</b> wrote:</p>
 <blockquote style="margin-left: 1em; border-left: 2px solid #d0d0d0; padding-left: 10px;">
  <pre style="white-space: pre-wrap; white-space: -moz-pre-wrap; white-space: -pre-wrap; white-space: -o-pre-wrap; word-wrap: break-word;">Scratch that, I want to investigate this a little more.  It seems like it&#39;s actually not getting into the while loop that causes the problem.  Should have looked over it more carefully.</pre>
 </blockquote>





 <p>On July 6th, 2011, 11:53 a.m., <b>kobaz</b> wrote:</p>
 <blockquote style="margin-left: 1em; border-left: 2px solid #d0d0d0; padding-left: 10px;">
  <pre style="white-space: pre-wrap; white-space: -moz-pre-wrap; white-space: -pre-wrap; white-space: -o-pre-wrap; word-wrap: break-word;">It seems to me that the higher level functions that use this need to be investigated.  The upper level calls to ack the timer should themselves be making sure they won&#39;t read an idle timer.  The upper level stuff should be aware of timers it needs to ack and only access ones that have events waiting.</pre>
 </blockquote>







</blockquote>
<pre style="margin-left: 1em; white-space: pre-wrap; white-space: -moz-pre-wrap; white-space: -pre-wrap; white-space: -o-pre-wrap; word-wrap: break-word;">This is actually more elaborate of a problem than I realized.  It seems that individual applications are relying on the timer_ack function in different ways to make connections.  The breakage from before was specifically from using an analog channel to call into a queue.  That would cause it to hit this function over and over again because it is looking for something to be set in the following do while loop.

I&#39;ve noticed that using other applications causes other weird behaviors.  MusicOnHold for instance will play the music on hold normally, but at that point performing a hanging up the analog phone will not cause the channel to start closing and the analog phone won&#39;t be able to start a new call.

I think the various SAY and playback applications are fine, even if you don&#39;t use them in a mode that performs an answer.

Here are a couple example backtraces where I forced a crash at the condition causing all these problems:

queue:

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0xb6954b70 (LWP 17873)]
0x02f12ec8 in timerfd_timer_ack (handle=46, quantity=1) at res_timing_timerfd.c:178
178                        pointer2[1] = &#39;a&#39;;
(gdb) bt
#0  0x02f12ec8 in timerfd_timer_ack (handle=46, quantity=1) at res_timing_timerfd.c:178
#1  0x081a2699 in ast_timer_ack (handle=0x86a07a8, quantity=1) at timing.c:169
#2  0x080b64bd in __ast_read (chan=0x867aad0, dropaudio=0) at channel.c:3788
#3  0x080b8661 in ast_read (chan=0x867aad0) at channel.c:4233
#4  0x023fcfa9 in wait_for_answer (qe=0xb694e29c, outgoing=0x85ebd18, to=0xb694c694, digit=0xb694c6a3 &quot;&quot;, prebusies=0, caller_disconnect=0, forwardsallowed=1, 
    update_connectedline=1) at app_queue.c:3803
#5  0x023ffba8 in try_calling (qe=0xb694e29c, options=0x0, announceoverride=0x0, url=0x0, tries=0xb694e270, noption=0xb694e26c, agi=0x0, macro=0x0, gosub=0x0, 
    ringing=0) at app_queue.c:4583
#6  0x02407c17 in queue_exec (chan=0x867aad0, data=0xb695175c &quot;markq&quot;) at app_queue.c:5992
#7  0x08146838 in pbx_exec (c=0x867aad0, app=0x85e9850, data=0xb695175c &quot;markq&quot;) at pbx.c:1406
#8  0x08150408 in pbx_extension_helper (c=0x867aad0, con=0x0, context=0x867ae3c &quot;analog&quot;, exten=0x867ae8c &quot;3700&quot;, priority=4, label=0x0, callerid=0x0, 
    action=E_SPAWN, found=0xb6953a68, combined_find_spawn=1) at pbx.c:4102
#9  0x08151eb3 in ast_spawn_extension (c=0x867aad0, context=0x867ae3c &quot;analog&quot;, exten=0x867ae8c &quot;3700&quot;, priority=4, callerid=0x0, found=0xb6953a68, 
    combined_find_spawn=1) at pbx.c:4625
#10 0x08152b34 in __ast_pbx_run (c=0x867aad0, args=0x0) at pbx.c:4723
#11 0x08155013 in ast_pbx_run_args (c=0x867aad0, args=0x0) at pbx.c:5096
#12 0x08155039 in ast_pbx_run (c=0x867aad0) at pbx.c:5105
#13 0x02be7e03 in __analog_ss_thread (data=0xb779a3f0) at sig_analog.c:2119
#14 0x081acaca in dummy_start (data=0x867b1b8) at utils.c:1004
#15 0x003fc96e in start_thread (arg=0xb6954b70) at pthread_create.c:300
#16 0x011bfa4e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130

musiconhold:

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0xb7355b70 (LWP 17945)]
0x02f12ec8 in timerfd_timer_ack (handle=46, quantity=1) at res_timing_timerfd.c:178
178                        pointer2[1] = &#39;a&#39;;
(gdb) bt
#0  0x02f12ec8 in timerfd_timer_ack (handle=46, quantity=1) at res_timing_timerfd.c:178
#1  0x081a2699 in ast_timer_ack (handle=0x88f94b8, quantity=1) at timing.c:169
#2  0x080b64bd in __ast_read (chan=0x8910bc0, dropaudio=0) at channel.c:3788
#3  0x080b8661 in ast_read (chan=0x8910bc0) at channel.c:4233
#4  0x080b12b7 in ast_safe_sleep_conditional (chan=0x8910bc0, ms=9981, cond=0, data=0x0) at channel.c:1830
#5  0x080b1447 in ast_safe_sleep (chan=0x8910bc0, ms=10000) at channel.c:1874
#6  0x01beb71a in play_moh_exec (chan=0x8910bc0, data=0xb735275c &quot;madplay&quot;) at res_musiconhold.c:751
#7  0x08146838 in pbx_exec (c=0x8910bc0, app=0x8573960, data=0xb735275c &quot;madplay&quot;) at pbx.c:1406
#8  0x08150408 in pbx_extension_helper (c=0x8910bc0, con=0x0, context=0x8910f2c &quot;analog&quot;, exten=0x8910f7c &quot;3702&quot;, priority=3, label=0x0, callerid=0x0, 
    action=E_SPAWN, found=0xb7354a68, combined_find_spawn=1) at pbx.c:4102
#9  0x08151eb3 in ast_spawn_extension (c=0x8910bc0, context=0x8910f2c &quot;analog&quot;, exten=0x8910f7c &quot;3702&quot;, priority=3, callerid=0x0, found=0xb7354a68, 
    combined_find_spawn=1) at pbx.c:4625
#10 0x08152b34 in __ast_pbx_run (c=0x8910bc0, args=0x0) at pbx.c:4723
#11 0x08155013 in ast_pbx_run_args (c=0x8910bc0, args=0x0) at pbx.c:5096
#12 0x08155039 in ast_pbx_run (c=0x8910bc0) at pbx.c:5105
#13 0x02be7e03 in __analog_ss_thread (data=0xb7930b08) at sig_analog.c:2119
#14 0x081acaca in dummy_start (data=0x88f7c80) at utils.c:1004
#15 0x003fc96e in start_thread (arg=0xb7355b70) at pthread_create.c:300
#16 0x011bfa4e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130

sayalpha (this one works just fine):

#0  0x02f12ec8 in timerfd_timer_ack (handle=46, quantity=1) at res_timing_timerfd.c:178
#1  0x081a2699 in ast_timer_ack (handle=0x88e7db8, quantity=1) at timing.c:169
#2  0x080b64bd in __ast_read (chan=0x88f5a30, dropaudio=0) at channel.c:3788
#3  0x080b8661 in ast_read (chan=0x88f5a30) at channel.c:4233
#4  0x08110f45 in waitstream_core (c=0x88f5a30, breakon=0x81ff77b &quot;&quot;, forward=0x81f47f6 &quot;&quot;, reverse=0x81f47f6 &quot;&quot;, skip_ms=0, audiofd=-1, cmdfd=-1, context=0x0)
    at file.c:1240
#5  0x08111459 in ast_waitstream (c=0x88f5a30, breakon=0x81ff77b &quot;&quot;) at file.c:1330
#6  0x0816f6f3 in say_character_str_full (chan=0x88f5a30, str=0xb6b4b75c &quot;\&quot;ABCDEFGHIJKLMNOPQRSTUVWXYZ\&quot;&quot;, ints=0x81ff77b &quot;&quot;, lang=0x88e17ec &quot;en&quot;, audiofd=-1, 
    ctrlfd=-1) at say.c:131
#7  0x080c678c in ast_say_character_str (chan=0x88f5a30, str=0xb6b4b75c &quot;\&quot;ABCDEFGHIJKLMNOPQRSTUVWXYZ\&quot;&quot;, ints=0x81ff77b &quot;&quot;, lang=0x88e17ec &quot;en&quot;) at channel.c:7983
#8  0x081669f4 in pbx_builtin_saycharacters (chan=0x88f5a30, data=0xb6b4b75c &quot;\&quot;ABCDEFGHIJKLMNOPQRSTUVWXYZ\&quot;&quot;) at pbx.c:9856
#9  0x08146838 in pbx_exec (c=0x88f5a30, app=0xb7d14d00, data=0xb6b4b75c &quot;\&quot;ABCDEFGHIJKLMNOPQRSTUVWXYZ\&quot;&quot;) at pbx.c:1406
#10 0x08150408 in pbx_extension_helper (c=0x88f5a30, con=0x0, context=0x88f5d9c &quot;analog&quot;, exten=0x88f5dec &quot;3703&quot;, priority=2, label=0x0, callerid=0x0, 
    action=E_SPAWN, found=0xb6b4da68, combined_find_spawn=1) at pbx.c:4102
#11 0x08151eb3 in ast_spawn_extension (c=0x88f5a30, context=0x88f5d9c &quot;analog&quot;, exten=0x88f5dec &quot;3703&quot;, priority=2, callerid=0x0, found=0xb6b4da68, 
    combined_find_spawn=1) at pbx.c:4625
#12 0x08152b34 in __ast_pbx_run (c=0x88f5a30, args=0x0) at pbx.c:4723
#13 0x08155013 in ast_pbx_run_args (c=0x88f5a30, args=0x0) at pbx.c:5096
#14 0x08155039 in ast_pbx_run (c=0x88f5a30) at pbx.c:5105
#15 0x02be7e03 in __analog_ss_thread (data=0x8812550) at sig_analog.c:2119
#16 0x081acaca in dummy_start (data=0x889e3e8) at utils.c:1004
#17 0x003fc96e in start_thread (arg=0xb6b4eb70) at pthread_create.c:300
#18 0x011bfa4e in clone () at ../sysdeps/unix/sysv/linux/i386/clone.S:130


Still not sure if that will help at all.</pre>
<br />




<p>- jrose</p>


<br />
<p>On June 3rd, 2011, 4:11 p.m., kobaz wrote:</p>






<table bgcolor="#fefadf" width="100%" cellspacing="0" cellpadding="8" style="background-image: url('https://reviewboard.asterisk.org/media/rb/images/review_request_box_top_bg.png'); background-position: left top; background-repeat: repeat-x; border: 1px black solid;">
 <tr>
  <td>

<div>Review request for Asterisk Developers and russelb.</div>
<div>By kobaz.</div>


<p style="color: grey;"><i>Updated June 3, 2011, 4:11 p.m.</i></p>




<h1 style="color: #575012; font-size: 10pt; margin-top: 1.5em;">Description </h1>
<table width="100%" bgcolor="#ffffff" cellspacing="0" cellpadding="10" style="border: 1px solid #b8b5a0">
 <tr>
  <td>
   <pre style="margin: 0; padding: 0; white-space: pre-wrap; white-space: -moz-pre-wrap; white-space: -pre-wrap; white-space: -o-pre-wrap; word-wrap: break-word;">Fix for issue https://issues.asterisk.org/view.php?id=18028
And several others.</pre>
  </td>
 </tr>
</table>


<h1 style="color: #575012; font-size: 10pt; margin-top: 1.5em;">Testing </h1>
<table width="100%" bgcolor="#ffffff" cellspacing="0" cellpadding="10" style="border: 1px solid #b8b5a0">
 <tr>
  <td>
   <pre style="margin: 0; padding: 0; white-space: pre-wrap; white-space: -moz-pre-wrap; white-space: -pre-wrap; white-space: -o-pre-wrap; word-wrap: break-word;">Make enough calls to trigger a read on an idle timer

Wait for message:
Reading attempt on idle timerfd. This would have caused a deadlock.

Deadlock avoided.</pre>
  </td>
 </tr>
</table>




<h1 style="color: #575012; font-size: 10pt; margin-top: 1.5em;">Diffs</b> </h1>
<ul style="margin-left: 3em; padding-left: 0;">

 <li>branches/1.8/res/res_timing_timerfd.c <span style="color: grey">(320171)</span></li>

</ul>

<p><a href="https://reviewboard.asterisk.org/r/1255/diff/" style="margin-left: 3em;">View Diff</a></p>




  </td>
 </tr>
</table>








  </div>
 </body>
</html>