[Home]

Summary:ASTERISK-29948: iostream: Infinite TCP timeout writing data
Reporter:N A (InterLinked)Labels:patch
Date Opened:2022-03-03 18:52:27.000-0600Date Closed:2022-04-26 14:12:52
Priority:MinorRegression?
Status:Closed/CompleteComponents:Core/General Core/Netsock
Versions:18.9.0 Frequency of
Occurrence
Frequent
Related
Issues:
Environment:Attachments:( 0) ASTERISK-29948.diff
( 1) ctbtpry4gq.txt
Description:I've noticed that my calls to open a new AMI connection can get blocked and hang forever.

Whenever this happens, if I do "core set debug 1", I can see that there seems to be an infinite loop of TCP failures:

{noformat}
[2022-03-04 00:48:00] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[1328]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[991]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[2345]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[1672]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[32735]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[474]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[2017]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[32410]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[2345]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[32735]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[991]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[1672]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[474]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[2017]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[1328]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[32410]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[32735]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[991]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[1672]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[474]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[2017]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[2345]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[1328]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:00] DEBUG[32410]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:01] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30181]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28196]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26872]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27008]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29701]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26256]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[26079]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27154]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[29234]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[30691]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27061]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[31373]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27662]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[28753]: iostream.c:484 ast_iostream_write: TCP timeout writing data
[2022-03-04 00:48:02] DEBUG[27092]: iostream.c:484 ast_iostream_write: TCP timeout writing data
{noformat}

The only fix I've come up with is to completely restart Asterisk.

It does not matter if there are any calls; this happens even on a system idle of calls.

In this last particular case, these TCP warnings came back less than an hour after Asterisk had been running.

While these are not warnings, it does mean something is wrong in this case as there are hundreds of each of these *per second*, and AMI is blocked forever for new connections (and possibly existing ones too).

Seems like Asterisk can get into a funny state where TCP has broken down and then the system is basically unusable for AMI until it is restarted.

However, no obvious impact to call process or anything like that - this seems to only break, as the errors suggest, TCP connections like AMI.
Comments:By: Asterisk Team (asteriskteam) 2022-03-03 18:52:29.236-0600

Thanks for creating a report! The issue has entered the triage process. That means the issue will wait in this status until a Bug Marshal has an opportunity to review the issue. Once the issue has been reviewed you will receive comments regarding the next steps towards resolution. Please note that log messages and other files should not be sent to the Sangoma Asterisk Team unless explicitly asked for. All files should be placed on this issue in a sanitized fashion as needed.

A good first step is for you to review the [Asterisk Issue Guidelines|https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines] if you haven't already. The guidelines detail what is expected from an Asterisk issue report.

Then, if you are submitting a patch, please review the [Patch Contribution Process|https://wiki.asterisk.org/wiki/display/AST/Patch+Contribution+Process].

Please note that once your issue enters an open state it has been accepted. As Asterisk is an open source project there is no guarantee or timeframe on when your issue will be looked into. If you need expedient resolution you will need to find and pay a suitable developer. Asking for an update on your issue will not yield any progress on it and will not result in a response. All updates are posted to the issue when they occur.

Please note that by submitting data, code, or documentation to Sangoma through JIRA, you accept the Terms of Use present at [https://www.asterisk.org/terms-of-use/|https://www.asterisk.org/terms-of-use/].

By: George Joseph (gjoseph) 2022-03-04 06:12:06.038-0600

Are you going to continue investigating this issue yourself?


By: N A (InterLinked) 2022-03-04 06:14:21.820-0600

I'm only reporting for now, I don't know what the underlying cause or issue is.

However, I can consistently reproduce this and this has happened at least 5 times in the past 12 hours now. I am having to constantly restart Asterisk at this point or everything AMI related completely breaks down until there is a restart.

My theory at the moment is that I have a test suite set up on Asterisk B which runs tests against Asterisk A. As part of this, it does a remote SSH during most of the tests where it runs a script that does AMI stuff and then exits. It seems like perhaps after this has been going on for a while, this issue starts to happen. However, I haven't pinpointed specifically where yet.

By: N A (InterLinked) 2022-03-04 06:24:03.570-0600

One guess is this may happen if an AMI connection is opened and then "abandoned" - however, I am still trying to confirm that. At that point, AMI is trying to send to something that isn't listening or engaging with it anymore, hence the "TCP timeout".

However, this then blocks ALL AMI traffic and really there needs to be a graceful abort if an AMI connection has gone dead like that for a while, to prevent it from taking the whole system down.

However, it sounds logical - would this make sense given the issue?

By: Joshua C. Colp (jcolp) 2022-03-07 13:49:17.457-0600

What are the contents of manager.conf? Can you also provide a backtrace from the running process?

By: N A (InterLinked) 2022-03-11 18:25:04.543-0600

manager.conf is as follows, essentially:

{noformat}

[general]
enabled = yes
webenabled = no
port = 5038
bindaddr = 127.0.0.1 ; 0.0.0.0
disabledevents = Newexten

[user1]
secret = secret
deny=0.0.0.0/0.0.0.0
permit=127.0.0.1/255.255.255.255
displayconnects = yes
read = call,agent
write = call,agent,originate

[user2]
secret = secret
deny=0.0.0.0/0.0.0.0
permit=127.0.0.1/255.255.255.255
displayconnects = yes
read = all
write = all

[user3]
secret = secret
deny=0.0.0.0/0.0.0.0
permit=127.0.0.1/255.255.255.255
displayconnects = yes
eventfilter = VoicemailUserDetail
read = call,config,all
write = originate,config,all

[user4]
secret = secret
deny=0.0.0.0/0.0.0.0
permit=127.0.0.1/255.255.255.255
displayconnects = yes
eventfilter = (Flash|Wink|Newstate|SuccessfulAuth)
eventfilter = (!VarSet|!Newexten|!ChallengeSent)
read = call,dtmf,cdr,security
write = originate,call,system

[amidump]
secret = secret
deny=0.0.0.0/0.0.0.0
permit=127.0.0.1/255.255.255.255
displayconnects = yes
read = all
write = all
{noformat}

Backtrace to follow soon; as it involves intentionally corrupting Asterisk, I need to do it in off-peak hours.


By: Asterisk Team (asteriskteam) 2022-03-27 12:00:00.991-0500

Suspended due to lack of activity. This issue will be automatically re-opened if the reporter posts a comment. If you are not the reporter and would like this re-opened please create a new issue instead. If the new issue is related to this one a link will be created during the triage process. Further information on issue tracker usage can be found in the Asterisk Issue Guidlines [1].

[1] https://wiki.asterisk.org/wiki/display/AST/Asterisk+Issue+Guidelines

By: N A (InterLinked) 2022-04-25 17:07:37.600-0500

Sorry for the delay on this one.
Backtrace attached.

After I fire up an improperly terminated expect script series, it only takes a few minutes to get this issue going.

Once present, the issue persists until Asterisk is restarted.

If I do a ps -aux and grep for the PHP scripts that are invoking the AMI connections, I see that indeed there are several scripts running.

This is the output of "manager show connected":

flash is a script that should run 24/7 via supervisorctl to process AMI events via callback functions.

The recentchange connections are all the problematic ones. If they don't terminate cleanly, then this causes TCP in Asterisk to completely blow up.

So, external AMI connections can bring an Asterisk system to its knees (as far as TCP is concerned) whenever they want.

{noformat}
voip*CLI> manager show connected
 Username         IP Address                                               Start       Elapsed     FileDes   HttpCnt   Read   Write
 flash            127.0.0.1                                                1650906039  18386       31        0         263426  04099
 recentchange     127.0.0.1                                                1650922165  2260        370       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650923797  628         244       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650924347  78          22        0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650924353  72          27        0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650924353  72          85        0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650924356  69          238       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650924358  67          242       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650924358  67          243       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650924374  51          277       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650924380  45          294       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650924411  14          293       0         2147483647  2147483647
12 users connected.

{noformat}

By: Asterisk Team (asteriskteam) 2022-04-25 17:07:38.541-0500

This issue has been reopened as a result of your commenting on it as the reporter. It will be triaged once again as applicable.

By: Joshua C. Colp (jcolp) 2022-04-25 17:38:27.974-0500

Please try the attached patch.

By: N A (InterLinked) 2022-04-25 17:52:16.178-0500

Yes, that seems to have fixed it.
I get the same MAX_INT nonsense for read/write stats but I don't see these TCP timeout debugs anymore:

{noformat}

voip*CLI> manager show connected
 Username         IP Address                                               Start       Elapsed     FileDes   HttpCnt   Read   Write
 flash            127.0.0.1                                                1650926726  333         25        0         263426  04099
 recentchange     127.0.0.1                                                1650926760  299         118       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650926803  256         111       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650926815  244         110       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650926818  241         116       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650926829  230         62        0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650926846  213         119       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650926917  142         127       0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650926983  76          60        0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650927022  37          52        0         2147483647  2147483647
 recentchange     127.0.0.1                                                1650927047  12          64        0         2147483647  2147483647

{noformat}

By: Joshua C. Colp (jcolp) 2022-04-25 18:41:25.459-0500

So is the session now terminated? What happens now?

By: N A (InterLinked) 2022-04-25 18:45:00.612-0500

They didn't go away immediately, but they weren't causing any issues.
I rebooted Server B which called the expect script to SSH into Server A which then spawned a PHP script which spawned an AMI connection to the Asterisk instance on Server A.

Interestingly, rebooting Server B did not close the manager connections even though the SSH connections would have dropped. But that could just be because AMI doesn't know when something has disconnected from it unless it explicitly "logs out". After all, it could just not have read or written to the socket.

(edit: maybe not true, as the socket would close, so not 100% sure...)

I checked now and most of those connections have since closed, but two are left.

I don't think this is necessarily a problem, since the connections weren't terminated cleanly. Regardless, they're not causing any issue to the rest of the system anymore.

By: Friendly Automation (friendly-automation) 2022-04-26 14:12:52.904-0500

Change 18427 merged by Friendly Automation:
manager: Terminate session on write error.

[https://gerrit.asterisk.org/c/asterisk/+/18427|https://gerrit.asterisk.org/c/asterisk/+/18427]

By: Friendly Automation (friendly-automation) 2022-04-26 15:36:44.769-0500

Change 18426 merged by Kevin Harwell:
manager: Terminate session on write error.

[https://gerrit.asterisk.org/c/asterisk/+/18426|https://gerrit.asterisk.org/c/asterisk/+/18426]

By: Friendly Automation (friendly-automation) 2022-04-26 15:37:01.306-0500

Change 18412 merged by Kevin Harwell:
manager: Terminate session on write error.

[https://gerrit.asterisk.org/c/asterisk/+/18412|https://gerrit.asterisk.org/c/asterisk/+/18412]

By: Friendly Automation (friendly-automation) 2022-04-26 15:37:11.321-0500

Change 18428 merged by Kevin Harwell:
manager: Terminate session on write error.

[https://gerrit.asterisk.org/c/asterisk/+/18428|https://gerrit.asterisk.org/c/asterisk/+/18428]