|
From: | Luis Soltero |
Subject: | [Linphone-users] Bug Report: Inbound SIP messages with Content-Type:text/plain; charset=UTF-8 broken in 3.12.0 |
Date: | Mon, 5 Nov 2018 11:59:53 -0500 |
User-agent: | Mozilla/5.0 (Macintosh; Intel Mac OS X 10.13; rv:52.0) Gecko/20100101 Thunderbird/52.9.1 |
Hello All, it seems that inbound SIP messages with "Content-Type:text/plain;charset=UTF-8" are not being processed correctly by linphone core 3.12. This used to work fine with linphone core 3.11. This was tested with the iOS version of LinPhone... iOS client based on core 3.11 received and displayed the messages in the chat screens without issue. When upgrading to iOS client based on the newer 3.12.0 core the old messages display fine. However, the content of any new messages arriving are either not displayed OR a download button is displayed. the Download button suggests that the client iOS app is interpreting the data as a link to be downloaded from a media server. Dumping the data from the XCode debugger shows that the data being stored is in binary format. to reproduce the problem a source for SIP MESSAGES with this content type is required. We use an Asterisk 11 PBX for this. Note that at this time its not possible to compile LinPhone core 3.11 with XCode 10. XCode 10 is required to support iOS 12. Here is a SIP trace between an asterisk pbx and the iOS client. Reliably Transmitting (no NAT) to 192.168.10.151:51746: MESSAGE sip:address@hidden:51746;transport=tcp SIP/2.0 Via: SIP/2.0/TCP 192.168.10.1:5060;branch=z9hG4bK3137c3a9 Max-Forwards: 70 From: "asterisk" <sip:address@hidden>;tag=as266022fe To: <sip:address@hidden:51746;transport=tcp> Contact: <sip:address@hidden:5060;transport=TCP> Call-ID: address@hidden:5060 CSeq: 102 MESSAGE User-Agent: Asterisk PBX 11.12.0 Content-Type: text/plain;charset=UTF-8 Content-Length: 12 test message --- Scheduling destruction of SIP dialog 'address@hidden:5060' in 6400 ms (Method: MESSAGE) -- Executing [201@messages:10] NoOp("Local/address@hidden;1", "Send status is SUCCESS") in new stack -- Executing [201@messages:11] GotoIf("Local/address@hidden;1", "0?sendfailedmsg") in new stack -- Executing [201@messages:12] Hangup("Local/address@hidden;1", "") in new stack == Spawn extension (messages, 201, 12) exited non-zero on 'Local/address@hidden;1' == Spawn extension (app-fakeanswer, 201, 6) exited non-zero on 'Local/address@hidden;2' [Nov 5 03:47:23] NOTICE[2104]: pbx_spool.c:402 attempt_thread: Call completed to Local/address@hidden <--- SIP read from TCP:192.168.10.151:51746 ---> MESSAGE sip:address@hidden SIP/2.0 Via: SIP/2.0/TCP 192.168.10.151:51746;branch=z9hG4bK.Z8H2TKIIo;rport From: <sip:address@hidden>;tag=DcxqFwUSh To: sip:address@hidden CSeq: 20 MESSAGE Call-ID: ubrynFGXTn Max-Forwards: 70 Supported: replaces, outbound, gruu Date: Mon, 05 Nov 2018 03:47:21 GMT Content-Encoding: deflate Content-Type: message/imdn+xml Content-Length: 209 Priority: non-urgent User-Agent: XGate.Phone_iPad.mini.2_iOS12.0.1/13d06679 (belle-sip/1.6.3) x?u??n? Dѳ<l??0?*_?i?s?B2?ȰQ??a???D???)?;?|?QS??ʓ?p-1?u???6SR[????P,???K9"?(օ?? ?f??r???X??B??Pk?Kѫ?L?V5??IuУ2??M?S??RM'?#?F8??u14h)?WB?LJ&?E v???o??faO]?aiiKkh]ͻ.?n?1C???ߒ?????`E <-------------> The message displays correctly in the linphone logs when it arrives... however, when enters the decoding segment of the code the data is not handled correctly and what arrives in the message is not store correctly on the device. here are the iOS linphone console logs. note 2018-11-03 18:02:54.431479-0700 XGate Phone[26943:4922238] [Message] Content type is unknown (text/plain;charset=UTF-8), don't try to decrypt it this seems to be coming from LIME which then passes this back to the core and the core continues to decode the message. Note that even with LIM disabled we still get the same behavior. 2018-11-03 18:02:54.415559-0700 XGate Phone[26943:4922238] [Message] Background task belle-sip recv channel started. Unknown remaining time since application is not fully in background. 2018-11-03 18:02:54.416165-0700 XGate Phone[26943:4922238] [Message] channel [0x10f69c000]: starting recv background task with id=[943]. 2018-11-03 18:02:54.416708-0700 XGate Phone[26943:4922238] [Message] channel [0x10f69c000]: received [481] new bytes from [TCP://192.168.10.1:5060]: 2018-11-03 18:02:54.416807-0700 XGate Phone[26943:4922238] [Message] MESSAGE sip:address@hidden:53140;transport=tcp SIP/2.0 2018-11-03 18:02:54.416957-0700 XGate Phone[26943:4922238] [Message] Via: SIP/2.0/TCP 192.168.10.1:5060;branch=z9hG4bK22b69fb9 2018-11-03 18:02:54.417106-0700 XGate Phone[26943:4922238] [Message] Max-Forwards: 70 2018-11-03 18:02:54.417258-0700 XGate Phone[26943:4922238] [Message] From: "asterisk" <sip:address@hidden>;tag=as53de6652 2018-11-03 18:02:54.417332-0700 XGate Phone[26943:4922238] [Message] To: <sip:address@hidden:53140;transport=tcp> 2018-11-03 18:02:54.417402-0700 XGate Phone[26943:4922238] [Message] Contact: <sip:address@hidden:5060;transport=TCP> 2018-11-03 18:02:54.417472-0700 XGate Phone[26943:4922238] [Message] Call-ID: address@hidden:5060 2018-11-03 18:02:54.417585-0700 XGate Phone[26943:4922238] [Message] CSeq: 102 MESSAGE 2018-11-03 18:02:54.417653-0700 XGate Phone[26943:4922238] [Message] User-Agent: Asterisk PBX 11.12.0 2018-11-03 18:02:54.417725-0700 XGate Phone[26943:4922238] [Message] Content-Type: text/plain;charset=UTF-8 2018-11-03 18:02:54.417829-0700 XGate Phone[26943:4922238] [Message] Content-Length: 13 2018-11-03 18:02:54.417897-0700 XGate Phone[26943:4922238] [Message] qwerty asdasd 2018-11-03 18:02:54.427368-0700 XGate Phone[26943:4922238] [Message] channel [0x10f69c000] [468] bytes parsed 2018-11-03 18:02:54.427815-0700 XGate Phone[26943:4922238] [Message] channel [0x10f69c000] read [13] bytes of body from [192.168.10.1:5060] 2018-11-03 18:02:54.429873-0700 XGate Phone[26943:4922238] [Message] Background task belle-sip transaction(0x2803341e0) started. Unknown remaining time since application is not fully in background. 2018-11-03 18:02:54.430138-0700 XGate Phone[26943:4922238] [Message] transaction [0x2803341e0]: starting transaction background task with id=[944]. 2018-11-03 18:02:54.430329-0700 XGate Phone[26943:4922238] [Message] Changing [server] [MESSAGE] transaction [0x2803341e0], from state [INIT] to [TRYING] 2018-11-03 18:02:54.431479-0700 XGate Phone[26943:4922238] [Message] Content type is unknown (text/plain;charset=UTF-8), don't try to decrypt it 2018-11-03 18:02:54.431885-0700 XGate Phone[26943:4922238] [Message] Chat message 0x10bc02b40: moving from State::Idle to State::Delivered 2018-11-03 18:02:54.432118-0700 XGate Phone[26943:4922238] [Message] Start measurement of [Find chat messages: (peer=sip:address@hidden, local=sip:address@hidden).]. 2018-11-03 18:02:54.432251-0700 XGate Phone[26943:4922238] [Message] Start transaction 0x16d6ac960 in MainDb::findChatMessages. 2018-11-03 18:02:54.433698-0700 XGate Phone[26943:4922238] [Message] Rollback transaction 0x16d6ac960 in MainDb::findChatMessages. 2018-11-03 18:02:54.434068-0700 XGate Phone[26943:4922238] [Message] Duration of [Find chat messages: (peer=sip:address@hidden, local=sip:address@hidden).]: 1ms. 2018-11-03 18:02:54.434496-0700 XGate Phone[26943:4922238] [Message] Linphone core [0x10901a200] notified [is_composing_received] 2018-11-03 18:02:54.434680-0700 XGate Phone[26943:4922238] [Message] Start transaction 0x16d6ac848 in MainDb::addEvent. 2018-11-03 18:02:54.443085-0700 XGate Phone[26943:4922238] [Message] Commit transaction 0x16d6ac848 in MainDb::addEvent. 2018-11-03 18:02:54.449664-0700 XGate Phone[26943:4922238] [Message] (LinphoneManager.m:1112) Decrementing index of long running task for call id : address@hidden:5060 with index : -1 2018-11-03 18:02:54.449980-0700 XGate Phone[26943:4922238] [Message] Linphone core [0x10901a200] notified [message_received] 2018-11-03 18:02:54.452216-0700 XGate Phone[26943:4922238] [Message] Skipping top route of initial route-set because same as request-uri 2018-11-03 18:02:54.452919-0700 XGate Phone[26943:4922238] [Message] Background task belle-sip transaction(0x280700000) started. Unknown remaining time since application is not fully in background. 2018-11-03 18:02:54.453134-0700 XGate Phone[26943:4922238] [Message] transaction [0x280700000]: starting transaction background task with id=[945]. 2018-11-03 18:02:54.454543-0700 XGate Phone[26943:4922238] [Message] Changing [client] [MESSAGE] transaction [0x280700000], from state [INIT] to [TRYING] 2018-11-03 18:02:54.455041-0700 XGate Phone[26943:4922238] [Message] Body has been compressed: 293->208: 2018-11-03 18:02:54.455106-0700 XGate Phone[26943:4922238] [Message] <?xml version="1.0" encoding="UTF-8" standalone="no" ?><imdn xmlns="urn:ietf:params:xml:ns:imdn"><message-id>address@hidden:5060</message-id><datetime>2018-11-04T01:02:54Z</datetime><delivery-notification><status><delivered/></status></delivery-notification></imdn> 2018-11-03 18:02:54.455252-0700 XGate Phone[26943:4922238] [Warning] message [0x281c76200] has Content-Length [293] and body size [208] which are inconsistent, fixing it. 2018-11-03 18:02:54.455501-0700 XGate Phone[26943:4922238] [Message] channel [0x10f69c000]: found binary data in buffer, will stop logging it now. 2018-11-03 18:02:54.455749-0700 XGate Phone[26943:4922238] [Message] channel [0x10f69c000]: message sent to [TCP://192.168.10.1:5060], size: [708] bytes 2018-11-03 18:02:54.464494-0700 XGate Phone[26943:4922238] [Message] MESSAGE sip:address@hidden SIP/2.0 2018-11-03 18:02:54.464573-0700 XGate Phone[26943:4922238] [Message] Via: SIP/2.0/TCP 192.168.10.121:53140;branch=z9hG4bK.PpvihE9g5;rport 2018-11-03 18:02:54.464608-0700 XGate Phone[26943:4922238] [Message] From: <sip:address@hidden>;tag=q-Ajf6e1m 2018-11-03 18:02:54.464637-0700 XGate Phone[26943:4922238] [Message] To: sip:address@hidden 2018-11-03 18:02:54.464665-0700 XGate Phone[26943:4922238] [Message] CSeq: 20 MESSAGE 2018-11-03 18:02:54.464692-0700 XGate Phone[26943:4922238] [Message] Call-ID: 38b20ao2tC 2018-11-03 18:02:54.464720-0700 XGate Phone[26943:4922238] [Message] Max-Forwards: 70 2018-11-03 18:02:54.464747-0700 XGate Phone[26943:4922238] [Message] Supported: replaces, outbound, gruu 2018-11-03 18:02:54.464775-0700 XGate Phone[26943:4922238] [Message] Date: Sun, 04 Nov 2018 01:02:54 GMT 2018-11-03 18:02:54.464803-0700 XGate Phone[26943:4922238] [Message] Content-Encoding: deflate 2018-11-03 18:02:54.466513-0700 XGate Phone[26943:4922238] [Message] Content-Type: message/imdn+xml 2018-11-03 18:02:54.466555-0700 XGate Phone[26943:4922238] [Message] Content-Length: 208 2018-11-03 18:02:54.466579-0700 XGate Phone[26943:4922238] [Message] Priority: non-urgent 2018-11-03 18:02:54.466603-0700 XGate Phone[26943:4922238] [Message] User-Agent: XGate.Phone_iPhone11.2_iOS12.0.1/4.0.2-184-g0494af563 (belle-sip/1.6.3) 2018-11-03 18:02:54.466674-0700 XGate Phone[26943:4922238] [Message] xúuè;n√0\^PDØB∞ßπTÙ° ävï\^S8M:Bª2\^HH+C§\^CÁˆ°ã\^XiÇÈfÊ\^Uœü\^^Î"æhœi„Qö\^CHA<mò¯: èÀª≤R‰\^R\^Y„≤1çí7)N¡ß\^UYTîÛ(Ô;ªDev∑∏«5ªZ;ŒÓyë¡ØîsºíJ\^X... (first 616 bytes shown) 2018-11-03 18:02:54.467902-0700 XGate Phone[26943:4922238] [Message] Changing [server] [MESSAGE] transaction [0x2803341e0], from state [TRYING] to [COMPLETED] 2018-11-03 18:02:54.468228-0700 XGate Phone[26943:4922238] [Message] channel [0x10f69c000]: message sent to [TCP://192.168.10.1:5060], size: [291] bytes 2018-11-03 18:02:54.470669-0700 XGate Phone[26943:4922238] [Message] SIP/2.0 200 Ok 2018-11-03 18:02:54.470712-0700 XGate Phone[26943:4922238] [Message] Via: SIP/2.0/TCP 192.168.10.1:5060;branch=z9hG4bK22b69fb9 2018-11-03 18:02:54.470739-0700 XGate Phone[26943:4922238] [Message] From: "asterisk" <sip:address@hidden>;tag=as53de6652 2018-11-03 18:02:54.470763-0700 XGate Phone[26943:4922238] [Message] To: <sip:address@hidden:53140;transport=tcp>;tag=0qYpcze 2018-11-03 18:02:54.470786-0700 XGate Phone[26943:4922238] [Message] Call-ID: address@hidden:5060 2018-11-03 18:02:54.470810-0700 XGate Phone[26943:4922238] [Message] CSeq: 102 MESSAGE 2018-11-03 18:02:54.470848-0700 XGate Phone[26943:4922238] [Message] Content-Length: 0 2018-11-03 18:02:54.471008-0700 XGate Phone[26943:4922238] [Message] Destroying op [0x108f02d10] of type [SalOpMessage] 2018-11-03 18:02:54.471114-0700 XGate Phone[26943:4922238] [Message] channel [0x10f69c000]: ending recv background task with id=[943]. 2018-11-03 18:02:54.491684-0700 XGate Phone[26943:4922238] [Message] Background task belle-sip recv channel started. Unknown remaining time since application is not fully in background. 2018-11-03 18:02:54.491920-0700 XGate Phone[26943:4922238] [Message] channel [0x10f69c000]: starting recv background task with id=[947]. 2018-11-03 18:02:54.492133-0700 XGate Phone[26943:4922238] [Message] channel [0x10f69c000]: received [433] new bytes from [TCP://192.168.10.1:5060]: 2018-11-03 18:02:54.492180-0700 XGate Phone[26943:4922238] [Message] SIP/2.0 415 Unsupported Media Type 2018-11-03 18:02:54.492206-0700 XGate Phone[26943:4922238] [Message] Via: SIP/2.0/TCP 192.168.10.121:53140;branch=z9hG4bK.PpvihE9g5;received=192.168.10.121;rport=53140 2018-11-03 18:02:54.492233-0700 XGate Phone[26943:4922238] [Message] From: <sip:address@hidden>;tag=q-Ajf6e1m 2018-11-03 18:02:54.492256-0700 XGate Phone[26943:4922238] [Message] To: sip:address@hidden;tag=as4e977ded 2018-11-03 18:02:54.492279-0700 XGate Phone[26943:4922238] [Message] Call-ID: 38b20ao2tC 2018-11-03 18:02:54.492302-0700 XGate Phone[26943:4922238] [Message] CSeq: 20 MESSAGE 2018-11-03 18:02:54.492325-0700 XGate Phone[26943:4922238] [Message] Server: Asterisk PBX 11.12.0 2018-11-03 18:02:54.492347-0700 XGate Phone[26943:4922238] [Message] Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE 2018-11-03 18:02:54.492446-0700 XGate Phone[26943:4922238] [Message] Supported: replaces, timer 2018-11-03 18:02:54.492482-0700 XGate Phone[26943:4922238] [Message] Content-Length: 0 2018-11-03 18:02:54.494631-0700 XGate Phone[26943:4922238] [Message] channel [0x10f69c000] [433] bytes parsed -- Luis Soltero, Ph.D., MCS Director of Software Development, CTO Global Marine Networks, LLC Tel: +1.865.379.8723 Fax: +1.865.681.5017 E-Mail: address@hidden Web: http://www.globalmarinenet.net Web: http://www.redportglobal.com |
[Prev in Thread] | Current Thread | [Next in Thread] |