[Linphone-users] Bug Report: Inbound SIP messages with Content-Type:text/plain; charset=UTF-8 broken in 3.12.0

[Luis Soltero]

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