error messages on Polycom phone logs

Marco Colaneri

unread,

May 21, 2021, 3:45:03 AM5/21/21

to sipxcom-users

Hi,

In our sipx enviroment, we have Poly VVX phones with 5.9.6 firmware.

Checking phone logs, I got these strange errors that repeat at variable time intervals:

May 21 05:21:50 x.x.x.x 64167fxxxxxx|0521052150|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen172614

May 21 05:26:52 x.x.x.x 64167fxxxxxx|0521052652|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen188884

May 21 05:29:28 x.x.x.x 64167fxxxxxx|0521052928|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen193892

May 21 05:30:28 x.x.x.x 64167fxxxxxx|0521053028|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen172295

May 21 05:33:44 x.x.x.x 64167fxxxxxx|0521053344|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen172535

May 21 05:34:32 x.x.x.x 64167fxxxxxx|0521053432|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen193874

May 21 05:50:32 x.x.x.x 64167fxxxxxx|0521055032|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen172302

May 21 05:58:06 x.x.x.x 64167fxxxxxx|0521055806|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen172899

May 21 06:03:23 x.x.x.x 64167fxxxxxx|0521060323|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen188323

May 21 06:07:34 x.x.x.x 64167fxxxxxx|0521060734|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen188917

May 21 06:22:36 x.x.x.x 64167fxxxxxx|0521062236|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen188490

May 21 06:33:32 x.x.x.x 64167fxxxxxx|0521063332|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen193894

May 21 06:34:21 x.x.x.x 64167fxxxxxx|0521063421|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen172200

May 21 06:37:45 x.x.x.x 64167fxxxxxx|0521063745|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen172574

May 21 06:39:52 x.x.x.x 64167fxxxxxx|0521063952|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen188531

May 21 06:45:39 x.x.x.x 64167fxxxxxx|0521064539|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen188972

Does anyone know what these errors are? Is it a normal behaviour?

Thanks a lot.

Iuliu Blaga

unread,

May 21, 2021, 6:29:34 AM5/21/21

to Marco Colaneri, sipxcom-users

Hi, Polycom logging is too low/high to see anything. You would need logging set to 3. I doubt this is a problem. Do you have any issues with the phone system?

https://community.polycom.com/t5/VoIP-SIP-Phones/FAQ-How-can-change-Logging-Levels-or-use-Syslog/td-p/4741

--
You received this message because you are subscribed to the Google Groups "sipxcom-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to sipxcom-user...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/sipxcom-users/618aada7-b881-4373-b17d-9beaa26a85e7n%40googlegroups.com.

--

Iuliu Blaga

Sr. Support Engineer

215.297.4400 x

751 Arbor Way, Arbor Crest I, Suite 150, Blue Bell, PA 19422
coredial.com

The information transmitted is intended only for the person or entity to which it is addressed and may contain confidential and/or privileged material. Any review, retransmission, dissemination or other use of, or taking of any action in reliance upon, this information by persons or entities other than the intended recipient is prohibited. If you received this in error, please contact the sender and delete the material from any computer.

Marco Colaneri

unread,

May 21, 2021, 2:21:26 PM5/21/21

to Iuliu Blaga, sipxcom-users

Thanks Iuliu for the advice.

On next monday I'll try to change the log level and check what it happens.

Until now we have got no issues on the phone system.

Bye.

Marco Colaneri

unread,

May 26, 2021, 10:53:48 AM5/26/21

to sipxcom-users

Hi,

I tried to increase log level of sip and hw applications on the phone. Here is the result.

I think that it is the normal closing of the TCP connection after expiration. Do you agree?

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |3|00|New Connection Accepted

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|hw |2|00|rtosLinuxTask: tTCPListen188924 - stack start 0x43029000 size 0x10000

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|Task name tTCPListen188924

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|MsgSipTcpAccept

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|socket accepted 25615064

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |3|00|Waiting for a New Connection 0x43067cb8 0x43067dc0

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |3|00|Creating recv Thread

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |3|00|Waiting on recv Thread

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|MsgSipTcpPacket

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |3|00|CStkDialog::IsThisDialog 'NOTIFY' contact '<sip:~~rl~C~10...@y.y.y.y:5140;x-sipX-nonat>' != '<sip:~~rl~C~10...@y.y.y.y:5140>' caused a Dialog Target Refresh

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |3|00|CStkDialog::CreateRouteSet m_TargetAddress updated from '<sip:~~rl~C~10...@y.y.y.y:5140>' to '<sip:~~rl~C~10...@y.y.y.y:5140;x-sipX-nonat>'

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |3|00|CStkDialog::CreateRouteSet: existing routeSet preserved

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |3|00|CStkDialog::CreateRouteSet: transport set to top route 'TCP'

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |2|00|active dialog after UPDATE being set here, m_pActiveDialog=0x15fde64,this=0x15fde64

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |2|00|CCallBase::IsChallenged 'NOTIFY' Dialog Tag 'A8D52169-C175415E' pRequest Tag 'A8D52169-C175415E' state 'Confirmed'

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |2|00|new UA Server Non-INVITE trans state 'callingTrying', timeout=0 (0x40edff48)

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |3|00|CCallNoCall::calculateNewExpire new expires = 5812

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |3|00|UA Server Non-INVITE NOTIFY trans state 'callingTrying'->'completed' by 200 resp 65 timeout(0x40edff48)

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|doDnsListLookup(tcp): doDnsSrvLookupForARecordList for 'y.y.y.y' port 43140 returned 1 results

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|doDnsListLookup(tcp): result 0 'y.y.y.y' port 43140 isInBound 0

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|doDnsListLookup(tcp): doDnsSrvLookupForARecordList for 'y.y.y.y' port 0 returned 1 results

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|doDnsListLookup(tcp): result 0 'y.y.y.y' port 0 isInBound 0

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|CTrans:: SendCommand | this=0x40edff48, bVQMonMessage=0, m_pCall->m_pUser->m_bOBFailOverReRegOn=0, m_pCall->m_pUser->m_bVQMonFailoverEnabled=1

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|Send: (TCP) entry for address y.y.y.y port 43140 can Connect 0 canFailOver 1

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|Send: (TCP) address y.y.y.y port 43140 can Connect 0

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|CPlcmSipTcpSocket::Send TCP queuedTxData = 0 TotalLen 529 loop count 1 maxQueueDepth 40000

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |2|00|CTrans::InitRetrans for UA Server Non-INVITE NOTIFY state 'completed' Server 2 of 2 (0x40edff48)

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |1|00|CStkDialog::SetDialogState: Dialog ';' State 'Trying'->'Terminated'

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |2|00|CCallNoCall::Notified full dialog-info 1 of 1 version rx 8369 local -1

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |3|00|CCallNoCall::NewDialogList: bIsBLF = 'true', nTotalDialog = '1', justRefresh = 'false', removeFromList = 'false'

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |2|00|New FULL DialogList for 'sip:10...@mydomain.it' state 'BLF' size 1

May 26 16:34:27 10.102.141.16 64167fcfca5e|0526163427|sip |3|00|Waiting on recv Thread

May 26 16:34:32 10.102.141.16 64167fcfca5e|0526163432|copy |4|00|Could not set the custom header Content-Range for HTTP/s request. Head request failed to get content-length of server file.

May 26 16:34:37 10.102.141.16 64167fcfca5e|0526163437|log |4|00|UtilLogServerC::uploadFifoLog: upload error. protocol 0 result = 14

May 26 16:34:37 10.102.141.16 64167fcfca5e|0526163437|log |4|00|UtilLogServerC::uploadFifoLog: upload error. protocol 0 result = -1

May 26 16:34:59 10.102.141.16 64167fcfca5e|0526163459|sip |1|00|CStkDialog::TimeOut500ms: Server State txn finished NOTIFY (0x15fde64)

May 26 16:36:26 10.102.141.16 64167fcfca5e|0526163626|sip |1|00|Plcm: socket 188(0x4276b6a8) time expires

May 26 16:36:26 10.102.141.16 64167fcfca5e|0526163626|sip |3|00|CPlcmSipTcpSocket::~CPlcmSipTcpSocket socket 188(0x4276b6a8) close

May 26 16:36:26 10.102.141.16 64167fcfca5e|0526163626|sip |1|00|socket recv error error=0

May 26 16:36:26 10.102.141.16 64167fcfca5e|0526163626|sip |1|00|ListenThread socket 0 thread exiting

May 26 16:36:26 10.102.141.16 64167fcfca5e|0526163626|hw |5|00|Task ended without calling rtosTaskEnd() name=tTCPListen188924

May 26 16:36:26 10.102.141.16 64167fcfca5e|0526163626|sip |3|00|~CSipStreamSocket : socket 0 entry for 0x4276b6a8

May 26 16:36:26 10.102.141.16 64167fcfca5e|0526163626|sip |1|00|MsgSipTcpSocketStatus socket 0 status 0 m_bIsReconnectNeeded 0

Iuliu Blaga

unread,

May 26, 2021, 12:07:23 PM5/26/21

to Marco Colaneri, sipxcom-users

Hi, yes, looks benign!

To view this discussion on the web visit https://groups.google.com/d/msgid/sipxcom-users/09b83abe-a902-479f-b03c-6d375f0b5d34n%40googlegroups.com.

Reply all

Reply to author

Forward