[Linphone-developers] iOS SIP Messaging issue with Content-Type:text/plain; charset=UTF-8

[Luis Soltero]

Hello,

Just compiled LinPhone for iOS 13d06679 with Core 3.12.0-3030-g065c01983

when sending LinPhone SIP messages in text/plain format from an Asterisk 11 server the message arrives and is displayed with no body.  Previous versions of LinPhone (e.g. using linphone core 3.11.2) work fine.

The following message shows up in the console

[Message] Content type is unknown (text/plain;charset=UTF-8), don't try to decrypt it

Any pointers on how to address this issue are greatly appreciated.

Here is an Asterisk SIP trace of the transaction.
<------------->
Really destroying SIP dialog 'k9tAecfOdX' Method: REGISTER
Really destroying SIP dialog 'ckm3plBU2h' Method: REGISTER
    -- Remote UNIX connection
    -- Remote UNIX connection disconnected
    -- Attempting call on Local/address@hidden for 201@messages:1 (Retry 1)
    -- Executing address@hidden:1] NoCDR("Local/address@hidden;2", "") in new stack
    -- Executing address@hidden:2] Set("Local/address@hidden;2", "DESTDEV=201") in new stack
    -- Executing address@hidden:3] Set("Local/address@hidden;2", "THISDEVSTATE=NOT_INUSE") in new stack
    -- Executing address@hidden:4] GotoIf("Local/address@hidden;2", "0?hang") in new stack
    -- Executing address@hidden:5] GotoIf("Local/address@hidden;2", "0?hang") in new stack
    -- Executing address@hidden:6] Answer("Local/address@hidden;2", "") in new stack
       > Channel Local/address@hidden;1 was answered
    -- Executing [201@messages:1] NoOp("Local/address@hidden;1", "SMS receiving dialplan invoked") in new stack
    -- Executing [201@messages:2] Set("Local/address@hidden;1", "ACTUALTO=sip:201") in new stack
    -- Executing [201@messages:3] Set("Local/address@hidden;1", "SRC="" class="moz-txt-link-rfc2396E" href="sip:address@hidden"><sip:address@hidden>") in new stack
    -- Executing [201@messages:4] Set("Local/address@hidden;1", "DST=sip:address@hidden") in new stack
    -- Executing [201@messages:5] Set("Local/address@hidden;1", "MSG=test message") in new stack
    -- Executing [201@messages:6] Set("Local/address@hidden;1", "OUTBOUND=0") in new stack
    -- Executing [201@messages:7] ExecIf("Local/address@hidden;1", "0?Set(ACTUALTO=sip:201)") in new stack
    -- Executing [201@messages:8] GotoIf("Local/address@hidden;1", "0?sendoutboundmessage") in new stack
    -- Executing [201@messages:9] MessageSend("Local/address@hidden;1", "sip:201,<sip:address@hidden>") in new stack
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
<------------->
--- (14 headers 1 lines) ---
Sending to 192.168.10.151:51746 (no NAT)
Receiving message!

<--- Transmitting (no NAT) to 192.168.10.151:51746 --->
SIP/2.0 415 Unsupported Media Type
Via: SIP/2.0/TCP 192.168.10.151:51746;branch=z9hG4bK.Z8H2TKIIo;received=192.168.10.151;rport=51746
From: <sip:address@hidden>;tag=DcxqFwUSh
To: sip:address@hidden;tag=as365db7de
Call-ID: ubrynFGXTn
CSeq: 20 MESSAGE
Server: Asterisk PBX 11.12.0
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog 'ubrynFGXTn' in 32000 ms (Method: MESSAGE)

<--- SIP read from TCP:192.168.10.151:51746 --->
SIP/2.0 200 Ok
Via: SIP/2.0/TCP 192.168.10.1:5060;branch=z9hG4bK3137c3a9
From: "asterisk" <sip:address@hidden>;tag=as266022fe
To: <sip:address@hidden:51746;transport=tcp>;tag=Svaq~Dr
Call-ID: address@hidden:5060
CSeq: 102 MESSAGE
Content-Length: 0

<------------->
--- (7 headers 0 lines) ---
Really destroying SIP dialog 'address@hidden:5060' Method: MESSAGE

here are the iOS console logs.

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