Re: [reSIProcate] repro crash with Jitsi
On 29/01/13 00:26, Byron Campen wrote:
> We should be tossing out the "full" response (mNextTransmission), but
> retaining the serialized retransmit buffer (mMsgToRetransmit). Did we ever
> successfully serialize/transmit this response? Perhaps there is a bug that
The 100 Trying response was sent about 3 seconds before the new PUBLISH
request
STACK | 20130127-160851.209 | repro | RESIP:TRANSPORT | 140422323181312
| ssl/TlsConnection.cxx:470 | Did TLS write 339 339 [[SIP/2.0 100 Trying
Via: SIP/2.0/TLS
192.168.1.100:49269;branch=z9hG4bK-373139-05d032d540e9bca18e3af732e0c948df
To: "1001" <sip:1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx>
From: "1001" <sip:1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx>;tag=c72de72a
Call-ID: 9e82664c30f04d33d1ce879ab846a60b@0:0:0:0:0:0:0:0
CSeq: 2 PUBLISH
Content-Length: 0
]]
STACK | 20130127-160854.895 | repro | RESIP:TRANSPORT | 140422323181312
| ssl/TlsConnection.cxx:317 | SSL_read returned 1 bytes [P]
STACK | 20130127-160854.895 | repro | RESIP:TRANSPORT | 140422323181312
| ssl/TlsConnection.cxx:369 | SSL bytesRead=1
DEBUG | 20130127-160854.895 | repro | RESIP:TRANSPORT | 140422323181312
| ConnectionBase.cxx:115 | In State: NewMessage
DEBUG | 20130127-160854.895 | repro | RESIP:TRANSPORT | 140422323181312
| ConnectionBase.cxx:161 | ConnectionBase::process setting source [ V4
192.168.1.100:49269 TLS target domain=unspecified mFlowKey=31 ]
DEBUG | 20130127-160854.895 | repro | RESIP:TRANSPORT | 140422323181312
| Connection.cxx:298 | Connection::performReads() read=1
STACK | 20130127-160854.895 | repro | RESIP:TRANSPORT | 140422323181312
| ssl/TlsConnection.cxx:317 | SSL_read returned 1352 bytes [UBLISH
sip:1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx SIP/2.0
Call-ID: 9e82664c30f04d33d1ce879ab846a60b@0:0:0:0:0:0:0:0
CSeq: 2 PUBLISH
From: "1001" <sip:1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx>;tag=c72de72a
To: "1001" <sip:1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx>
Max-Forwards: 70
Content-Type: application/pidf+xml
Contact: "1001"
<sip:1001@192.168.1.100:49269;transport=tls;registering_acc=srv1_office_readytechnology_co_uk>
User-Agent: Jitsi1.1.4400.10268Windows 7
Expires: 3600
Event: presence
Via: SIP/2.0/TLS
192.168.1.100:49269;branch=z9hG4bK-373139-05d032d540e9bca18e3af732e0c948df
Proxy-Authorization: Digest
username="1001",realm="srv1.office.readytechnology.co.uk",nonce="1359299327:1ba2dffdf6697b06053efcfe4736f581",uri="sip:1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx",response="71efd5b4af3d25d2405c0e84d9c8e4eb",algorithm=MD5,qop=auth,cnonce="xyz",nc=00000001
Content-Length: 452
> broke the serialization? Been a very long time since I've looked at this...
>
> Best regards,
> Byron Campen
>
>
> On Mon, Jan 28, 2013 at 10:00 AM, Scott Godin <sgodin@xxxxxxxxxxxxxxx>wrote:
>
>> The assert is indicating a bug so it is valid.
>>
>> After a quick look at the offending code, my guess is that we have
>> received a re-transmission of a non-invite request (ie PUBLISH) after we
>> have formed and sent our response, and we are supposed to be re-responding
>> with the same response as last time. However one of the code changes made
>> in the resip-b-TKLC-perf_work branch merge was to throw away the
>> mNextTransmission if it is a response. I suspect the purpose was to try
>> and free up some memory as soon as possible. However I see at least two
>> places in the code where re-transmitting a stored response is required.
>> 1. Appears to be what you have found - Server Non-Invite transaction
>> after receiving a re-transmitted requested for which we have already
>> responded.
>> 2. When TimerG expires (Server Invite transaction) and we need to re
>> transmit an Invite response when we don't see the resulting ACK.
>>
>> I am inclined to just comment out the code block starting on line 2567 in
>> order to fix this:
>> // !bwc! If mNextTransmission is a non-ACK request, we need to
>> save the
>> // initial request in case we need to send a simulated 408 or a
>> 503 to
>> // the TU (at least, until we get a response back)
>> if(!mNextTransmission->isRequest() ||
>> mNextTransmission->method()==ACK)
>> {
>> delete mNextTransmission;
>> mNextTransmission=0;
>> }
>>
>> However I'd like for Byron to chime in here, since these were originally
>> his changes.
>>
>> Regards,
>> Scott
>>
>> On Sun, Jan 27, 2013 at 4:44 PM, Daniel Pocock <daniel@xxxxxxxxxxxxx>wrote:
>>
>>>
>>>
>>>
>>> I had heard about this in a private email, and have been `lucky' enough
>>> to observe it myself now, with a full log at STACK level too
>>>
>>> The UA (sip:1001@srv1) is Jitsi v1.1.4400.10268 and repro is r9959 (main)
>>>
>>> The packet from Jitsi is below - has anyone seen similar issues with
>>> presence requests or Jitsi? Should the assert(0) be triggered there,
>>> does it actually indicate something is wrong, or should I just compile
>>> with NDEBUG and ignore it?
>>>
>>>
>>>
>>> The code in question is
>>>
>>> void
>>> TransactionState::sendCurrentToWire()
>>> {
>>> if(!mMsgToRetransmit.empty())
>>> {
>>> if(mController.mStack.statisticsManagerEnabled())
>>> {
>>> mController.mStatsManager.retransmitted(mCurrentMethodType,
>>> isClient(),
>>> mCurrentResponseCode);
>>> }
>>>
>>> mController.mTransportSelector.retransmit(mMsgToRetransmit);
>>> }
>>> else if(mNextTransmission) // initial transmission; need to determine
>>> target
>>> {
>>> ... snip ...
>>> }
>>> else
>>> { // line 2578
>>> assert(0);
>>> }
>>>
>>>
>>>
>>> DEBUG | 20130127-160854.896 | repro | RESIP:TRANSPORT | 140422323181312
>>> | ConnectionBase.cxx:418 | ##Connection: CONN_BASE: 0x7fb6a8234460 [ V4
>>> 192.168.1.100:49269 TLS target domain=unspecified mFlowKey=31 ]
>>> received: PUBLISH sip:1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx SIP/2.0
>>> Via: SIP/2.0/TLS
>>> 192.168.1.100:49269
>>> ;branch=z9hG4bK-373139-05d032d540e9bca18e3af732e0c948df
>>> Max-Forwards: 70
>>> Contact: "1001"
>>> <sip:1001@192.168.1.100:49269
>>> ;transport=tls;registering_acc=srv1_office_readytechnology_co_uk>
>>> To: "1001" <sip:1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx>
>>> From: "1001" <sip:1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx>;tag=c72de72a
>>> Call-ID: 9e82664c30f04d33d1ce879ab846a60b@0:0:0:0:0:0:0:0
>>> CSeq: 2 PUBLISH
>>> Expires: 3600
>>> Content-Type: application/pidf+xml
>>> Proxy-Authorization: Digest
>>> username="1001",realm="srv1.office.readytechnology.co.uk
>>> ",nonce="1359299327:1ba2dffdf6697b06053efcfe4736f581",uri="
>>> sip:1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
>>> ",response="71efd5b4af3d25d2405c0e84d9c8e4eb",algorithm=MD5,qop=auth,cnonce="xyz",nc=00000001
>>> User-Agent: Jitsi1.1.4400.10268Windows 7
>>> Event: presence
>>> Content-Length: 452
>>>
>>> <?xml version="1.0" encoding="UTF-8" standalone="no"?><presence
>>> xmlns="urn:ietf:params:xml:ns:pidf"
>>> xmlns:dm="urn:ietf:params:xml:ns:pidf:data-model"
>>> xmlns:rpid="urn:ietf:params:xml:ns:pidf:rpid"
>>> entity="sip:1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"><dm:person
>>> id="p556"><rpid:activities/></dm:person><tuple
>>> id="t6311"><status><basic>open</basic></status><contact>
>>> sip:1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
>>> </contact><note>Online</note></tuple></presence>
>>> DEBUG | 20130127-160854.896 | repro | RESIP:TRANSPORT | 140422323181312
>>> | Connection.cxx:298 | Connection::performReads() read=1352
>>> DEBUG | 20130127-160854.896 | repro | RESIP:TRANSPORT | 140422323181312
>>> | ConnectionBase.cxx:661 | Creating buffer for CONN_BASE: 0x7fb6a8234460
>>> [ V4 192.168.1.100:49269 TLS target domain=unspecified mFlowKey=31 ]
>>> STACK | 20130127-160854.896 | repro | RESIP:TRANSPORT | 140422323181312
>>> | ssl/TlsConnection.cxx:317 | SSL_read returned -1 bytes []
>>> STACK | 20130127-160854.896 | repro | RESIP:TRANSPORT | 140422323181312
>>> | ssl/TlsConnection.cxx:354 | Got TLS read got condition of 2
>>> STACK | 20130127-160854.896 | repro | RESIP:TRANSACTION |
>>> 140422331574016 | TransactionState.cxx:706 | Found matching transaction
>>> for SipReq: PUBLISH 1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
>>> tid=-373139-05d032d540e9bca18e3af732e0c948df cseq=2 PUBLISH
>>> contact=1001@192.168.1.100:49269 / 2 from(wire)
>>> tlsd=srv1.office.readytechnology.co.uk ->
>>> tid=-373139-05d032d540e9bca18e3af732e0c948df [
>>> ServerNonInvite/Proceeding reliable target=[ V4 192.168.1.100:49269 TLS
>>> target domain=unspecified mFlowKey=31 ]]
>>> STACK | 20130127-160854.896 | repro | RESIP:TRANSACTION |
>>> 140422331574016 | TransactionState.cxx:1438 |
>>> TransactionState::processServerNonInvite: SipReq: PUBLISH
>>> 1001@xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
>>> tid=-373139-05d032d540e9bca18e3af732e0c948df cseq=2 PUBLISH
>>> contact=1001@192.168.1.100:49269 / 2 from(wire)
>>> tlsd=srv1.office.readytechnology.co.uk
>>> repro: TransactionState.cxx:2578: void
>>> resip::TransactionState::sendCurrentToWire(): Assertion `0' failed.
>>> _______________________________________________
>>> resiprocate-devel mailing list
>>> resiprocate-devel@xxxxxxxxxxxxxxx
>>> https://list.resiprocate.org/mailman/listinfo/resiprocate-devel
>>>
>>
>>
>> _______________________________________________
>> resiprocate-devel mailing list
>> resiprocate-devel@xxxxxxxxxxxxxxx
>> https://list.resiprocate.org/mailman/listinfo/resiprocate-devel
>>
>