From: "Dmitry Akindinov" Received: by mx.demos.su (CommuniGate Pro PIPE 5.0.14) with PIPE id 548262352; Mon, 17 Dec 2012 22:15:51 +0400 X-Spam-Status: No, hits=-1.3 required=5.0 tests=AWL,BAYES_00,NORMAL_HTTP_TO_IP, RP_MATCHES_RCVD,SPF_HELO_PASS,SPF_PASS,WEIRD_PORT autolearn=ham version=3.3.2-st1.demos X-Spam-Level: X-Spam-Checker-Version: SpamAssassin 3.3.2-st1.demos (2011-06-06) X-Spam-Report: -1.3 points, 5.0 required; * -0.0 SPF_HELO_PASS SPF: HELO matches SPF record * -0.0 SPF_PASS SPF: sender matches SPF record * -0.8 RP_MATCHES_RCVD Envelope sender domain matches handover relay domain * 0.0 NORMAL_HTTP_TO_IP URI: Uses a dotted-decimal IP address in URL * 0.0 WEIRD_PORT URI: Uses non-standard port number for HTTP * -0.5 BAYES_00 BODY: Bayes spam probability is 0 to 1% * [score: 0.0000] * -0.0 AWL AWL: From: address is in the auto white-list Received: from moscow.stalker.com ([89.175.185.228] verified) by mx.demos.su (CommuniGate Pro SMTP 5.0.14) with ESMTP id 548262355 for CGatePro@mx.ru; Mon, 17 Dec 2012 22:15:43 +0400 Received: from [37.204.163.96] (account dimak@mail.moscow.stalker.com HELO [192.168.0.112]) by mail.moscow.stalker.com (CommuniGate Pro SMTP 6.0.1d) with ESMTPSA id 35531031 for CGatePro@mx.ru; Mon, 17 Dec 2012 22:15:38 +0400 Message-ID: <50CF6147.7040001@stalker.com> Date: Mon, 17 Dec 2012 22:15:35 +0400 Organization: Stalker Labs User-Agent: Mozilla/5.0 (Windows NT 6.1; rv:13.0) Gecko/20120614 Thunderbird/13.0.1 MIME-Version: 1.0 To: CommuniGate Pro Russian Discussions Subject: Re: [CGP] CGP_6 =?KOI8-R?Q?=EF=C2=D2=D7=D9=D7_=DA=D7=CF=CE=CB=C1?= =?KOI8-R?Q?_=DE=C5=D2=C5=DA_1-3_=CD=C9=CE=2E_=28Error_Code=3DB?= =?KOI8-R?Q?ridge_time-out=29?= References: In-Reply-To: Content-Type: text/plain; charset=KOI8-R; format=flowed Content-Transfer-Encoding: 8bit Здравствуйте, On 2012-12-17 21:47, Andre Jouch wrote: > Добрый день. > > Подлкючили к CGP-6 2x-портовый Linksys PAP2, проблема не наблюдается > звонки ходят нормально, > на Cisco телефонах попробовали 3 разных прошивки > (cmterm-7941_7961-sip.8-3-4SR1.zip > ,cmterm-7941_7961-sip.8-3-5.zip > , > cmterm-7941_7961-sip.8-4-2.zip) проблема остается, на CGP-5.8 проблема > не наблюдается. > > Из лога телефона видно что пакета начинают сыпатся где то за 30 сек. до > разрыва (message detected but failed to find valid coupled message) > > Вопрос: В какой версии проблема 5.8 или 6. Вы бы всё-таки воспроизвели проблему с полными логами, как предлагалось уже: Real-Time -> SIP -> sending -> Transport == All Info Real-Time -> Nodes == Low level Real-Time -> Signals -> Call Dialogs == All Info затем воспроизвести обрыв, собрать лог от начала звонка до времени обрыва + 5 секунд и прислать его на support@communigate.com. Заранее спасибо. > Спасибо. > > > > > > 2012/12/16 Andre Jouch > > > Добрый день, > > Увеличили с дефолтных 3 мин до 5 но результата нет, хотя телефоны с > версией 5.8 работают нормально, лог звонка ниже > > 22:28:16.001 1 PBXLEG-009850 session refresh failed > 22:28:16.001 2 PBXLEG-009850 disconnected > 22:28:16.001 2 PBXLEG-009850 bridge(NODE-009852) breaking > 22:28:16.001 2 PBXLEG-009850 Event([bridgeUpdate]) from NODE-009852 retrieved > 22:28:16.001 1 PBXLEG-009850 got bridge-updating event from an unknown source > 22:28:16.001 2 PBXLEG-009850 Event([bridgeDestroy]) from NODE-009852 retrieved > 22:28:16.001 1 PBXLEG-009850 got an un-bridge event from an unknown source > 22:28:16.001 2 PBXLEG-009850 Event([disconnect]) retrieved > > > > > 2012/12/16 Dmitry Akindinov > > > > Здравствуйте, > > On 2012-12-16 23:39, Andre Jouch wrote: > > Добрый день. > > > > Поставили для теста последнюю 6 версию под Linux, то того > была версия > > 5.8, откатились обратно на 5.8 > > > > На данный момент разговоры идущие через PBX прерываются между > 1-3 мин, к > > серверу подключали > > Сisco телефоны 7941 и 7911 которые работают с версией 5.8 без > проблем, > > ниже лог из сервера и телефона. > > > > > > > > 21:12:38.850 5 PBXLEG-009382 DOWNSTREAM posted > > 21:12:38.850 5 NODE(2) 009382: processing DOWNSTREAM > > 21:12:38.850 4 PBXLEG-009382 INVITE response ACK'ed > > 21:12:38.850 5 PBXLEG-009382 leg state=0 > > 21:12:38.850 5 PBXLEG-009382 timeout set for 300 secs > > 21:12:38.850 4 PBXLEG-009382 signalling completed(bridge-ACKwait) > > 21:12:38.850 5 PBXLEG-009382 pbx state=1(bridge-linking > completed), active > > 21:12:38.850 2 PBXLEG-009382 bridge-linking completed > > 21:12:38.850 5 PBXLEG-009382 timeout cleared > > 21:12:38.850 4 PBXLEG-009382 waiting for input (60 sec) > > 21:12:38.850 5 PBXLEG-009382 pbx state=5(waiting for an > event), timeout=60s > > 21:12:38.850 5 PBXLEG-009382 timeout set for 60 secs > > 21:12:38.850 5 NODE(2) 009382: enqueued (60 secs) > > 21:13:00.017 4 PBXLEG-009386 enqueued > > 21:13:38.000 5 NODE(1) 009384: timeout > > 21:13:38.000 5 NODE(8) 009382: timeout > > 21:13:38.000 4 PBXLEG-009384 timeout > > 21:13:38.000 4 PBXLEG-009382 timeout > > 21:13:38.000 5 PBXLEG-009384 pbx state=1(waiting > interrupted), active > > 21:13:38.000 5 PBXLEG-009382 pbx state=1(waiting > interrupted), active > > 21:13:38.001 4 PBXLEG-009384 waiting for input (60 sec) > > 21:13:38.001 5 PBXLEG-009384 pbx state=5(waiting for an > event), timeout=60s > > 21:13:38.001 4 PBXLEG-009382 waiting for input (60 sec) > > 21:13:38.001 5 PBXLEG-009384 timeout set for 34 secs > > 21:13:38.001 5 PBXLEG-009382 pbx state=5(waiting for an > event), timeout=60s > > 21:13:38.001 5 NODE(1) 009384: enqueued (34 secs) > > 21:13:38.001 5 PBXLEG-009382 timeout set for 32 secs > > 21:13:38.001 5 NODE(8) 009382: enqueued (32 secs) > > 21:14:10.001 2 PBXLEG-009382 refreshing with OPTIONS > > 21:14:10.001 4 PBXLEG-009382 session timer refreshed > > 21:14:10.001 4 PBXLEG-009382 SIGNAL-043132 sending OPTIONS > > sip:XXXXX@192.168.0.8:5060 > ;__transport=udp > > 21:14:10.001 5 PBXLEG-009382 leg state=2 > > 21:14:10.001 5 NODE(6) 009382: idling > > 21:14:27.000 5 NODE(6) 009384: timeout > > 21:14:27.000 4 PBXLEG-009384 timeout > > 21:14:27.000 1 PBXLEG-009384 bridge update transaction timed-out > > 21:14:27.000 4 PBXLEG-009384 bridge() update transaction failed > > 21:14:27.000 4 PBXLEG-009384 delayed SDP acknowledgement > arrived(Bridge > > time-out) > > 21:14:27.000 4 PBXLEG-009384 sending ACK CSeq=3 > > 21:14:27.000 2 SIPDATA-000000 created SIPC-014500 to send > downstream > > 21:14:27.000 5 PBXLEG-009384 leg state=0 > > 21:14:27.000 5 PBXLEG-009384 timeout immediate set > > 21:14:27.000 1 PBXLEG-009384 bridge() update transaction > failed. Error > > Code=Bridge time-out > > 21:14:27.000 2 PBXLEG-009384 bridge(NODE-009382) breaking > > 21:14:27.000 5 PBXLEG-009382 EVENT posted > > По этим логам можно предположить, что звонок был сделан через > B2BUA приложение и оно проверяет, что сессия всё еще жива, > посылая телефонам OPTIONS. А они не отвечают. > Коррелирует ли продолжительность звонка до обрыва с временем > сессий в webAdmin -> Settings -> Real-Time -> Nodes -> Call Lejs > -> Session Expiration? > > > > > > ------------------------------__------------------------------__------------------------------__----- > > > > ERR 21:26:43.801506 JVM: sipRelDevCoupledMessageSend: Error: > Duplicate > > message detected but failed to find valid coupled message. Stored > > message not sent. > > ERR 21:26:43.802803 JVM: sipSPICheckRequest: Error: > > sipRelDevCoupledMessageSend() returned error. > > ERR 21:26:44.800582 JVM: sipRelDevCoupledMessageSend: Error: > Duplicate > > message detected but failed to find valid coupled message. Stored > > message not sent. > > ERR 21:26:44.801571 JVM: sipSPICheckRequest: Error: > > sipRelDevCoupledMessageSend() returned error. > > ERR 21:26:48.801299 JVM: sipRelDevCoupledMessageSend: Error: > Duplicate > > message detected but failed to find valid coupled message. Stored > > message not sent. > > ERR 21:26:48.802660 JVM: sipSPICheckRequest: Error: > > sipRelDevCoupledMessageSend() returned error. > > ERR 21:26:52.800497 JVM: sipRelDevCoupledMessageSend: Error: > Duplicate > > message detected but failed to find valid coupled message. Stored > > message not sent. > > ERR 21:26:52.801770 JVM: sipSPICheckRequest: Error: > > sipRelDevCoupledMessageSend() returned error. > > ERR 21:26:56.800466 JVM: sipRelDevCoupledMessageSend: Error: > Duplicate > > message detected but failed to find valid coupled message. Stored > > message not sent. > > ERR 21:26:56.801811 JVM: sipSPICheckRequest: Error: > > sipRelDevCoupledMessageSend() returned error. > > ERR 21:27:00.799395 JVM: sipRelDevCoupledMessageSend: Error: > Duplicate > > message detected but failed to find valid coupled message. Stored > > message not sent. > > ERR 21:27:00.800875 JVM: sipSPICheckRequest: Error: > > sipRelDevCoupledMessageSend() returned error. > > ERR 21:27:03.026314 DSP: read/write UDP error, total 10, errno > > 146:Connection refused > > Эти логи, к сожалению, мне совсем ни о чём не говорят. > > Лучше бы увеличить уровень логов: > > Real-Time -> SIP -> sending -> Transport == All Info > Real-Time -> Nodes == Low level > Real-Time -> Signals -> Call Dialogs == All Info > > затем воспроизвести обрыв, собрать лог от начала звонка до > времени обрыва + 5 секунд и прислать его на > support@communigate.com . > Заранее спасибо. [] -- Best regards, Dmitry Akindinov