Project

General

Profile

Bug #2520

DeliverSM received sometimes with wrong message reference

Added by pespin about 1 year ago. Updated 19 days ago.

Status:
Closed
Priority:
Normal
Assignee:
Target version:
-
Start date:
09/25/2017
Due date:
% Done:

0%

Spec Reference:

Description

From time to time, tests checking SMS Delivery Receipts in osmo-gsm-tester fail due to receiving a DeliverSM with an unexpected user_message_reference value.

The issue seems to be present both in osmo-nitb and in new osmo-msc, when running osmo-gsm-tester test esme_ms_sms_storeforward.py.

The issue is spotted in https://jenkins.osmocom.org/jenkins/view/osmo-gsm-tester/job/osmo-gsm-tester_run/3042/, I'll upload the test tgz output in here.

In both osmo-msc and osmo-nitb, the isse is the following:

00:23:39.121625 tst   esme_ms_sms_storeforward.py:55: checking MS can receive SMS while registered...  [trial-3042↪aoip_smpp↪esme_ms_sms_storeforward.py:55]  [esme_ms_sms_storeforward.py:55]
00:23:39.302422 tst                       esme-24924: Sending SMS "message nr. 14, smpp send already-registered message, from 24924, to 24925" to 24925  [trial-3042↪aoip_smpp↪esme-24924]  [esme.py:144]
00:23:39.339940 tst                       esme-24924: DBG: sent part with seq 4  [trial-3042↪aoip_smpp↪esme-24924]  [esme.py:162]
00:23:39.375312 tst                       esme-24924: DBG: pdus_pending: [4]  [trial-3042↪aoip_smpp↪esme-24924]  [esme.py:177]
00:23:39.412995 tst                       esme-24924: DBG: message sent resp with seq 4 , pdus_pending: [4]  [trial-3042↪aoip_smpp↪esme-24924]  [esme.py:169]
00:23:43.460011 tst                       esme-24924: DBG: message received: {seq=1517561744}  [trial-3042↪aoip_smpp↪esme-24924]  [esme.py:120]
00:23:43.496919 tst                       esme-24924: DBG: message received:  AlertNotification: {ms_availability_status='0'}  [trial-3042↪aoip_smpp↪esme-24924]  [esme.py:122]
00:23:44.539055 tst                        /sierra_2: Incoming SMS: 'message nr. 14, smpp send already-registered message, from 24924, to 24925'  [trial-3042↪aoip_smpp↪/sierra_2]  [ofono_client.py:547]
00:23:44.575626 tst                        /sierra_2: DBG: {info={LocalSentTime='2017-09-25T00:23:42+0200', Sender='+24924', SentTime='2017-09-25T00:23:42+0200'}}  [trial-3042↪aoip_smpp↪/sierra_2]  [ofono_client.py:548]
00:23:44.612108 tst                        /sierra_2: SMS received as expected: 'message nr. 14, smpp send already-registered message, from 24924, to 24925'  [trial-3042↪aoip_smpp↪/sierra_2]  [ofono_client.py:554]
00:23:44.648968 tst                        /sierra_2: DBG: {info={LocalSentTime='2017-09-25T00:23:42+0200', Sender='+24924', SentTime='2017-09-25T00:23:42+0200'}}  [trial-3042↪aoip_smpp↪/sierra_2]  [ofono_client.py:555]
00:23:44.756595 tst   esme_ms_sms_storeforward.py:59: Waiting to receive and consume sms receipt with reference 2  [trial-3042↪aoip_smpp↪esme_ms_sms_storeforward.py:59]  [esme_ms_sms_storeforward.py:59]
00:23:49.950516 tst                       esme-24924: DBG: message received: {seq=1517561745}  [trial-3042↪aoip_smpp↪esme-24924]  [esme.py:120]
00:23:49.988599 tst                       esme-24924: DBG: message received: DeliverSM {references_pending_receipt=[2], user_message_reference=165}  [trial-3042↪aoip_smpp↪esme-24924]  [esme.py:125]
00:23:49.992277 tst   esme_ms_sms_storeforward.py:60: ERR: ValueError: list.remove(x): x not in list  [trial-3042↪aoip_smpp↪esme_ms_sms_storeforward.py:60]  [esme.py:126: self.references_pending_receipt.remove(umref)]

^ Expecting DeliverSM with user reference 2 but received 165

00:18:10.228228 tst   esme_ms_sms_storeforward.py:46: checking MS can receive SMS while registered...  [trial-3042↪smpp↪esme_ms_sms_storeforward.py:46]  [esme_ms_sms_storeforward.py:46]
00:18:10.419603 tst                       esme-24917: Sending SMS "message nr. 9, smpp send already-registered message, from 24917, to 24918" to 24918  [trial-3042↪smpp↪esme-24917]  [esme.py:144]
00:18:10.461079 tst                       esme-24917: DBG: sent part with seq 5  [trial-3042↪smpp↪esme-24917]  [esme.py:162]
00:18:10.498199 tst                       esme-24917: DBG: pdus_pending: [5]  [trial-3042↪smpp↪esme-24917]  [esme.py:177]
00:18:10.537632 tst                       esme-24917: DBG: message sent resp with seq 5 , pdus_pending: [5]  [trial-3042↪smpp↪esme-24917]  [esme.py:169]
00:18:13.584413 tst                       esme-24917: DBG: message received: {seq=1425383599}  [trial-3042↪smpp↪esme-24917]  [esme.py:120]
00:18:13.623841 tst                       esme-24917: DBG: message received: DeliverSM {references_pending_receipt=[3], user_message_reference=163}  [trial-3042↪smpp↪esme-24917]  [esme.py:125]
00:18:13.628528 tst   esme_ms_sms_storeforward.py:49: ERR: ValueError: list.remove(x): x not in list  [trial-3042↪smpp↪esme_ms_sms_storeforward.py:49]  [esme.py:126: self.references_pending_receipt.remove(umref)]

^ Expecting DeliverSM with user reference 3 but received 163

pcap file with RSL+OML+GSMTAP traffic for the test with osmo-nitb can be found inside the tgz in run.2017-09-25_00-05-22/smpp/esme_ms_sms_storeforward.py/osmo-nitb_10.42.42.2/pcap/. Traffic coming/going to the ESME is not recorded due to bug #2413. According to the osmo-gsm-tester logs, the python code implementing the ESME, the umref sent should be 3, but from what can be seen in the pcap file, the RP-Message Reference in GSMTAP is 0x0, and if I remember correctly we copy the SMPP ref to use the same value in the Um protocol, so they should be the same.

Still to check if the issue is related to following bits still missing in the osmo-gsm-tester esme implementation: #2452

trial-3042-run.tgz trial-3042-run.tgz 727 KB pespin, 09/25/2017 10:54 AM

History

#1 Updated by neels about 1 year ago

(reminds me of the report by rhizomatica that rarely but regularly people receive SMS addressed to a completely unrelated subscriber...)

#2 Updated by laforge 20 days ago

pespin: Does this still happen these days?

#3 Updated by pespin 19 days ago

  • Status changed from New to Closed

I don't remember seeing this for a long while now, closing it.

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 48.8 MB)