Restart of sbc-rtp due to unhandled / malformed message format in rtpengine-client

[Catharsis68]

"msg":"Uncaught exception error caught. Error was: malformed/unexpected message format ff1a266e-ada2-4b82-b48b-4cbe87cd62c2 "

RtpEngineError: malformed/unexpected message format

d10:statisticsd17:currentstatisticsd11:sessionsowni0e15:sessionsforeigni0e13:sessionstotali0e15:transcodedmediai0e15:packetrate_useri0e13:byterate_useri0e14:errorrate_useri0e17:packetrate_kerneli0e15:byterate_kerneli0e16:errorrate_kerneli0e10:packetratei0e8:byteratei0e9:errorratei0e15:media_userspacei0e12:media_kerneli0e11:media_mixedi0ee15:totalstatisticsd6:uptime6:50284315:managedsessionsi18137e16:rejectedsessionsi0e15:timeoutsessionsi0e21:silenttimeoutsessionsi0e20:finaltimeoutsessionsi0e20:offertimeoutsessionsi0e25:regularterminatedsessionsi18137e24:forcedterminatedsessionsi0e19:relayedpackets_useri127302507e24:relayedpacketerrors_useri6837e17:relayedbytes_useri21800459624e21:relayedpackets_kerneli0e26:relayedpacketerrors_kerneli0e19:relayedbytes_kerneli0e14:relayedpacketsi127302507e19:relayedpacketerrorsi6837e12:relayedbytesi21800459624e14:zerowaystreamsi98e13:onewaystreamsi12e15:avgcallduration9:69.70882818:totalcallsduration14:1264309.01532319:totalcallsduration216:257014651.14372025:totalcallsduration_stddev9:96.495679e3:mosd9:mos_total14:4678549.30000010:mos2_total15:20221550.91000017:mos_samples_totali1082978e11:mos_average8:4.30000010:mos_stddev8:0.000000e12:voip_metricsd12:jitter_total13:731878.00000013:jitter2_total17:1155315350.00000020:jitter_samples_totali1105151e14:jitter_average8:0.00000013:jitter_stddev9:32.00000013:rtt_e2e_total18:19690762321.00000014:rtt_e2e2_total22:611155480571753.00000021:rtt_e2e_samples_totali1105151e15:rtt_e2e_average12:17817.00000014:rtt_e2e_stddev12:15347.00000014:rtt_dsct_total18:12289803364.00000015:rtt_dsct2_total22:236695640591962.00000022:rtt_dsct_samples_totali1105151e16:rtt_dsct_average12:11120.00000015:rtt_dsct_stddev11:9513.00000016:packetloss_total12:52609.00000017:packetloss2_total14:4280313.00000024:packetloss_samples_totali1105151e18:packetloss_average8:0.00000017:packetloss_stddev8:1.00000021:jitter_measured_total8:0.00000022:jitter_measured2_total8:0.00000029:jitter_measured_samples_totali0e23:jitter_measured_average8:0.00000022:jitter_measured_stddev8:0.00000012:packets_losti0e14:rtp_duplicatesi0e9:rtp_skipsi0e14:rtp_seq_resetsi0e13:rtp_reorderedi0ee17:controlstatisticsd7:proxiesld5:proxy9:127.0.0.19:pingcounti0e12:pingduration8:0.00000010:offercounti0e13:offerduration8:0.00000011:answercounti0e14:answerduration8:0.00000011:deletecounti0e14:deleteduration8:0.00000010:querycounti0e13:queryduration8:0.0000009:listcounti0e12:listduration8:0.00000013:startreccounti0e16:startrecduration8:0.00000012:stopreccounti0e15:stoprecduration8:0.00000013:pausereccounti0e16:pauserecduration8:0.00000013:startfwdcounti0e16:startfwdduration8:0.00000012:stopfwdcounti0e15:stopfwdduration8:0.00000012:blkdtmfcounti0e15:blkdtmfduration8:0.00000014:unblkdtmfcounti0e17:unblkdtmfduration8:0.00000013:blkmediacounti0e16:blkmediaduration8:0.00000015:unblkmediacounti0e18:unblkmediaduration8:0.00000014:playmediacounti0e17:playmediaduration8:0.00000014:stopmediacounti0e17:stopmediaduration8:0.00000013:playdtmfcounti0e16:playdtmfduration8:0.00000010:statscounti16760e13:statsduration9:32.07991713:slnmediacounti0e16:slnmediaduration8:0.00000015:unslnmediacounti0e18:unslnmediaduration8:0.0000008:pubcounti0e11:pubduration8:0.00000011:subreqcounti0e14:subreqduration8:0.00000011:subanscounti0e14:subansduration8:0.00000010:unsubcounti0e13:unsubduration8:0.00000010:errorcounti0eed5:proxy11:10.1.138.739:pingcounti25138e12:pingduration8:0.01845610:offercounti9481e13:offerduration8:3.16797411:answercounti9434e14:answerduration8:2.16027311:deletecounti13368e14:deleteduration8:0.51775010:querycounti0e13:queryduration8:0.0000009:listcounti0e12:listduration8:0.00000013:startreccounti0e16:startrecduration8:0.00000012:stopreccounti0e15:stoprecduration8:0.00000013:pausereccounti0e16:pauserecduration8:0.00000013:startfwdcounti0e16:startfwdduration8:0.00000012:stopfwdcounti0e15:stopfwdduration8:0.00000012:blkdtmfcounti0e15:blkdtmfduration8:0.00000014:unblkdtmfcounti0e17:unblkdtmfduration8:0.00000013:blkmediacounti0e16:blkmediaduration8:0.00000015:unblkmediacounti0e18:unblkmediaduration8:0.00000014:playmediacounti0e17:playmediaduration8:0.00000014:stopmediacounti0e17:stopmediaduration8:0.00000013:playdtmfcounti0e16:playdtmfduration8:0.00000010:statscounti0e13:statsduration8:0.00000013:slnmediacounti0e16:slnmediaduration8:0.00000015:unslnmediacounti0e18:unslnmediaduration8:0.0000008:pubcounti0e11:pubduration8:0.00000011:subreqcounti0e14:subreqduration8:0.00000011:subanscounti0e14:subansduration8:0.00000010:unsubcounti0e13:unsubduration8:0.00000010:errorcounti0eed5:proxy12:10.1.137.2469:pingcounti25140e12:pingduration8:0.01827010:offercounti101e13:offerduration8:0.03480811:answercounti99e14:answerduration8:0.01977911:deletecounti40e14:deleteduration8:0.00256410:querycounti0e13:queryduration8:0.0000009:listcounti0e12:listduration8:0.00000013:startreccounti0e16:startrecduration8:0.00000012:stopreccounti0e15:stoprecduration8:0.00000013:pausereccounti0e16:pauserecduration8:0.00000013:startfwdcounti0e16:startfwdduration8:0.00000012:stopfwdcounti0e15:stopfwdduration8:0.00000012:blkdtmfcounti0e15:blkdtmfduration8:0.00000014:unblkdtmfcounti0e17:unblkdtmfduration8:0.00000013:blkmediacounti0e16:blkmediaduration8:0.00000015:unblkmediacounti0e18:unblkmediaduration8:0.00000014:playmediacounti0e17:playmediaduration8:0.00000014:stopmediacounti0e17:stopmediaduration8:0.00000013:playdtmfcounti0e16:playdtmfduration8:0.00000010:statscounti0e13:statsduration8:0.00000013:slnmediacounti0e16:slnmediaduration8:0.00000015:unslnmediacounti0e18:unslnmediaduration8:0.0000008:pubcounti0e11:pubduration8:0.00000011:subreqcounti0e14:subreqduration8:0.00000011:subanscounti0e14:subansduration8:0.00000010:unsubcounti0e13:unsubduration8:0.00000010:errorcounti0eed5:proxy11:10.1.130.469:pingcounti25139e12:pingduration8:0.01797010:offercounti87e13:offerduration8:0.03240111:answercounti84e14:answerduration8:0.01710211:deletecounti39e14:deleteduration8:0.00255010:querycounti0e13:queryduration8:0.0000009:listcounti0e12:listduration8:0.00000013:startreccounti0e16:startrecduration8:0.00000012:stopreccounti0e15:stoprecduration8:0.00000013:pausereccounti0e16:pauserecduration8:0.00000013:startfwdcounti0e16:startfwdduration8:0.00000012:stopfwdcounti0e15:stopfwdduration8:0.00000012:blkdtmfcounti0e15:blkdtmfduration8:0.00000014:unblkdtmfcounti0e17:unblkdtmfduration8:0.00000013:blkmediacounti0e16:blkmediaduration8:0.00000015:unblkmediacounti0e18:unblkmediaduration8:0.00000014:playmediacounti0e17:playmediaduration8:0.00000014:stopmediacounti0e17:stopmediaduration8:0.00000013:playdtmfcounti0e16:playdtmfduration8:0.00000010:statscounti0e13:statsduration8:0.00000013:slnmediacounti0e16:slnmediaduration8:0.00000015:unslnmediacounti0e18:unslnmediaduration8:0.0000008:pubcounti0e11:pubduration8:0.00000011:subreqcounti0e14:subreqduration8:0.00000011:subanscounti0e14:subansduration8:0.00000010:unsubcounti0e13:unsubduration8:0.00000010:errorcounti0eed5:proxy11:10.1.134.489:pingcounti25137e12:pingduration8:0.01847710:offercounti9671e13:offerduration8:3.23003911:answercounti9633e14:answerduration8:2.20914611:deletecounti13170e14:deleteduration8:0.52480610:querycounti0e13:queryduration8:0.0000009:listcounti0e12:listduration8:0.00000013:startreccounti0e16:startrecduration8:0.00000012:stopreccounti0e15:stoprecduration8:0.00000013:pausereccounti0e16:pauserecduration8:0.00000013:startfwdcounti0e16:startfwdduration8:0.00000012:stopfwdcounti0e15:stopfwdduration8:0.00000012:blkdtmfcounti0e15:blkdtmfduration8:0.00000014:unblkdtmfcounti0e17:unblkdtmfduration8:0.00000013:blkmediacounti0e16:blkmediaduration8:0.00000015:unblkmediacounti0e18:unblkmediaduration8:0.00000014:playmediacounti0e17:playmediaduration8:0.00000014:stopmediacounti0e17:stopmediaduration8:0.00000013:playdtmfcounti0e16:playdtmfduration8:0.00000010:statscounti0e13:statsduration8:0.00000013:slnmediacounti0e16:slnmediaduration8:0.00000015:unslnmediacounti0e18:unslnmediaduration8:0.0000008:pubcounti0e11:pubduration8:0.00000011:subreqcounti0e14:subreqduration8:0.00000011:subanscounti0e14:subansduration8:0.00000010:unsubcounti0e13:unsubduration8:0.00000010:errorcounti0eee14:totalpingcounti100554e15:totaloffercounti19340e16:totalanswercounti19250e16:totaldeletecounti26617e15:totalquerycounti0e14:totallistcounti0e18:totalstartreccounti0e17:totalstopreccounti0e18:totalpausereccounti0e18:totalstartfwdcounti0e17:totalstopfwdcounti0e17:totalblkdtmfcounti0e19:totalunblkdtmfcounti0e18:totalblkmediacounti0e20:totalunblkmediacounti0e19:totalplaymediacounti0e19:totalstopmediacounti0e18:totalplaydtmfcounti0e15:totalstatscounti16760e18:totalslnmediacounti0e20:totalunslnmediacounti0e13:totalpubcounti0e16:totalsubreqcounti0e16:totalsubanscounti0e15:totalunsubcounti0ee10:interfacesld4:name7:private7:address11:10.1.151.845:portsd3:mini40000e3:maxi60000e4:usedi1e8:used_pct4:0.004:freei20000e6:totalsi20001ee12:packets_losti0e10:duplicatesi0e12:voip_metricsd9:mos_total14:3764883.30000010:mos2_total15:16271239.53000017:mos_samples_totali871276e11:mos_average8:4.30000010:mos_stddev8:0.00000012:jitter_total13:643423.00000013:jitter2_total17:1154751091.00000020:jitter_samples_totali892214e14:jitter_average8:0.00000013:jitter_stddev9:35.00000013:rtt_e2e_total18:15891638435.00000014:rtt_e2e2_total22:493923510713555.00000021:rtt_e2e_samples_totali892214e15:rtt_e2e_average12:17811.00000014:rtt_e2e_stddev12:15373.00000014:rtt_dsct_total18:11097123673.00000015:rtt_dsct2_total22:193506402088493.00000022:rtt_dsct_samples_totali892214e16:rtt_dsct_average12:12437.00000015:rtt_dsct_stddev11:7885.00000016:packetloss_total11:1117.00000017:packetloss2_total12:25793.00000024:packetloss_samples_totali892214e18:packetloss_average8:0.00000017:packetloss_stddev8:0.00000021:jitter_measured_total8:0.00000022:jitter_measured2_total8:0.00000029:jitter_measured_samples_totali0e23:jitter_measured_average8:0.00000022:jitter_measured_stddev8:0.000000e7:ingressd7:packetsi64202601e5:bytesi10984265048e6:errorsi26ee6:egressd7:packetsi63248743e5:bytesi10839969496e6:errorsi0eeed4:name6:public7:address11:10.1.151.845:portsd3:mini40000e3:maxi60000e4:usedi1e8:used_pct4:0.004:freei20000e6:totalsi20001ee12:packets_losti0e10:duplicatesi0e12:voip_metricsd9:mos_total13:913666.00000010:mos2_total14:3950311.38000017:mos_samples_totali211702e11:mos_average8:4.30000010:mos_stddev8:0.01000012:jitter_total12:88455.00000013:jitter2_total13:564259.00000020:jitter_samples_totali212937e14:jitter_average8:0.00000013:jitter_stddev8:1.00000013:rtt_e2e_total17:3799123886.00000014:rtt_e2e2_total22:117231969858198.00000021:rtt_e2e_samples_totali212937e15:rtt_e2e_average12:17841.00000014:rtt_e2e_stddev12:15239.00000014:rtt_dsct_total17:1192679691.00000015:rtt_dsct2_total21:43189238503469.00000022:rtt_dsct_samples_totali212937e16:rtt_dsct_average11:5601.00000015:rtt_dsct_stddev12:13094.00000016:packetloss_total12:51492.00000017:packetloss2_total14:4254520.00000024:packetloss_samples_totali212937e18:packetloss_average8:0.00000017:packetloss_stddev8:4.00000021:jitter_measured_total8:0.00000022:jitter_measured2_total8:0.00000029:jitter_measured_samples_totali0e23:jitter_measured_average8:0.00000022:jitter_measured_stddev8:0.000000e7:ingressd7:packetsi63391048e5:bytesi10842401044e6:errorsi56ee6:egressd7:packetsi64047007e5:bytesi11391990658e6:errorsi6755eeee11:transcodersld5:chain22:G722/8000 -> PCMU/80003:numi0e7:packetsi0e5:bytesi0e7:samplesi0eed5:chain22:PCMA/8000 -> PCMU/80003:numi0e7:packetsi3589e5:bytesi574240e7:samplesi574240eed5:chain22:PCMA/8000 -> PCMA/80003:numi0e7:packetsi153403e5:bytesi24544480e7:samplesi24544480eed5:chain25:opus/48000/2 -> PCMU/80003:numi0e7:packetsi0e5:bytesi0e7:samplesi0eed5:chain31:DTMF injector/8000 -> PCMA/80003:numi0e7:packetsi0e5:bytesi0e7:samplesi0eed5:chain22:PCMU/8000 -> PCMA/80003:numi0e7:packetsi3533e5:bytesi565280e7:samplesi565280eeee6:result2:oke

[nvwx]

I just saw the same crash. I'm still trying to figure out what message went over to rtpengine-client that caused the crash.

RtpEngineError: malformed/unexpected message format ��p�
                                                        ��K_)q�ޟ?��!��A��!�Q=IZ8�ݩ�=�m�nh6���w�y�Y
�EjZ��Q�RR�                                                                                      ��*��
    at Client._onMessage (/home/app/node_modules/rtpengine-client/lib/BaseClient.js:62:26)
    at Socket.emit (node:events:507:28)
    at UDP.onMessage [as onmessage] (node:dgram:948:8)

Environment:

• drachtio-srf (5.0.0)
• @jambonz/rtpengine-utils (0.1.22)
• rtpengine-client (0.2.1)
• rtpengine Version: 11.3.1.1+0~mr11.3.1.1 git-HEAD-82d54c10
• drachtio v0.9.0-rc2-2-ga888707a64