Hi, Time passed but my DLR problem is still here, and I've got now 2 kannel servers for 3 modems, and the problem of the non-reliable "Delivered" DLRs appears on the 3 modems...
I checked with Multitech support, and they seems to agree on the fact that Kannel is making the problem here. I sent them those 2 cases (one success / one failure): the success one: 2017-05-19 12:43:59 [455] [6] DEBUG: AT2[multic3]: <-- +CDS: 25 2017-05-19 12:43:59 [455] [6] DEBUG: AT2[multic3]: <-- 07913366003000F006220B913366930401F3715091014400807150910144008000 2017-05-19 12:43:59 [455] [6] DEBUG: AT2[multic3]: received message from SMSC: +33660003000 <+33%206%2060%2000%2030%2000> *2017-05-19 12:43:59 [455] [6] DEBUG: AT2[multic3]: got STATUS-REPORT for message <34>:* *2017-05-19 12:43:59 [455] [6] DEBUG: AT2[multic3]: Numeric receiver (international) <+33663940103 <+33%206%2063%2094%2001%2003>>* *2017-05-19 12:43:59 [455] [6] DEBUG: DLR[internal]: Looking for DLR smsc=multic3, ts=34, dst=+33663940103 <+33%206%2063%2094%2001%2003>, type=1* 2017-05-19 12:43:59 [455] [6] DEBUG: DLR[internal]: created DLR message for URL <http://localhost/playsms/index.php?app=call&cat=gateway&plu gin=kannel&access=dlr&type=%d&smslog_id=277&uid=2&smsc=multic3> 2017-05-19 12:44:01 [455] [6] DEBUG: AT2[multic3]: TP-Validity-Period: 24.0 hours and here is the failing one: 2017-05-19 12:47:47 [455] [6] DEBUG: DLR[internal]: Adding DLR smsc=multic3, ts=39, src=1234, dst=+33614472199 <+33%206%2014%2047%2021%2099>, mask=31, boxc= 2017-05-19 12:47:47 [455] [6] DEBUG: SMSC[multic3]: creating DLR message 2017-05-19 12:47:47 [455] [6] DEBUG: SMSC[multic3]: DLR = http://localhost/playsms/index.php?app=call&cat=gateway&pl ugin=kannel&access=dlr&type=%d&smslog_id=545&uid=2&smsc=multic3 2017-05-19 12:47:50 [455] [6] DEBUG: AT2[multic3]: <-- +CDS: 25 2017-05-19 12:47:50 [455] [6] DEBUG: AT2[multic3]: <-- 07913366003000F006250B913316442791F9715091018400807150910184008000 2017-05-19 12:47:50 [455] [6] DEBUG: AT2[multic3]: received message from SMSC: +33660003000 <+33%206%2060%2000%2030%2000> *2017-05-19 12:47:50 [455] [6] DEBUG: AT2[multic3]: got STATUS-REPORT for message <37>:* *2017-05-19 12:47:50 [455] [6] DEBUG: AT2[multic3]: Numeric receiver (international) <+33614472199 <+33%206%2014%2047%2021%2099>>* *2017-05-19 12:47:50 [455] [6] DEBUG: DLR[internal]: Looking for DLR smsc=multic3, ts=37, dst=+33614472199 <+33%206%2014%2047%2021%2099>, type=1* 2017-05-19 12:47:50 [455] [6] WARNING: DLR[internal]:* DLR from SMSC<multic3> for DST<+33614472199 <+33%206%2014%2047%2021%2099>> not found.* 2017-05-19 12:47:50 [455] [6] DEBUG: AT2[multic3]: *Received delivery notification but can't find that ID in the DLR storage* 2017-05-19 12:47:50 [455] [6] DEBUG:* System error 1: Operation not permitted* 2017-05-19 12:47:50 [455] [6] ERROR: AT2[multic3]: *could not decode PDU to a message*. And here is the response from Multitech: *Your test 1:Module output following acknowledgement to application which module received from network:07913366003000F006250B913316442791F9715091018400807150910184008000Your test 2:Module output following acknowledgement to application which module received from network:07913366003000F006220B913366930401F3715091014400807150910144008000Your test 1 & 2When you look at modem output side by side structure is identical07913366003000F006250B913316442791F971509101840080715091018400800007913366003000F006220B913366930401F3715091014400807150910144008000Per Steve suggestion I used SMS application to interpret the acknowledgments and it had no issues with either message. So it appears the error is not due to the structure of the acknowledgment. See attached images illustrating the messages are similar in structure and not in error. The module forwards acknowledgements it receives from network to the application when the messages arrive. Message received from network/output to application appears to be structurally correct. This does not appear to be a device/module issue but an issue with SMS software not finding a match for acknowledgement being received from cellular network. This assessment is based on log indicating "can't find that ID in the DLR storage." We are not familiar with this software so we would suggest you ask SMS application support why their application is not finding a match for acknowledgements received from network in 40-60% of cases.* So, how do I fix this wierd bug ? And also, how I'm the only one getting this ? Can anyone help me make the Delivered DLR works with Kannel ? If it needs to change the source code of Kannel, I'm okay with that, but just give me some hints on where I can find the bug in the source code. Thanks, *Hakim BIMAZGANE* *Lead Developer* Vit*alliance* 2016-10-20 18:16 GMT+02:00 Hakim Bimazgane <hakim.bimazg...@vitalliance.fr>: > Hi, > > I'm using Kannel version 1.5.0 on a Debian x64 with PlaySMS 1.4. > I use a MultiTech MultiConnect Cell 100 (MTC-H5-B03-KIT) as GSM modem. > > I got some problems with some DLRs (concatened SMS activated). > > I see on my app and on playSMS that I receive the "sent" status, but I got > very rarely the "delivered" status. > > I don't know, but I think it's about errors I got after the +CDS command: > > 2016-10-20 17:23:37 [22525] [6] DEBUG: AT2[multic1]: detecting modem type > 2016-10-20 17:23:37 [22525] [6] INFO: AT2[multic1]: opening device > 2016-10-20 17:23:37 [22525] [6] DEBUG: AT2[multic1]: device opened. Telnet > mode = 0 > 2016-10-20 17:23:38 [22525] [6] DEBUG: AT2[multic1]: device opened > 2016-10-20 17:23:38 [22525] [6] INFO: AT2[multic1]: speed set to 115200 > 2016-10-20 17:23:38 [22525] [6] DEBUG: AT2[multic1]: --> ATZ^M > 2016-10-20 17:23:38 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:38 [22525] [6] DEBUG: AT2[multic1]: --> AT^M > 2016-10-20 17:23:38 [22525] [6] DEBUG: AT2[multic1]: <-- AT > 2016-10-20 17:23:38 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:38 [22525] [6] DEBUG: AT2[multic1]: --> ^M > 2016-10-20 17:23:40 [22525] [6] DEBUG: AT2[multic1]: --> AT^M > 2016-10-20 17:23:40 [22525] [6] DEBUG: AT2[multic1]: <-- AT > 2016-10-20 17:23:40 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:40 [22525] [6] DEBUG: AT2[multic1]: --> AT&F^M > 2016-10-20 17:23:40 [22525] [6] DEBUG: AT2[multic1]: <-- AT&F > 2016-10-20 17:23:40 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:40 [22525] [6] DEBUG: AT2[multic1]: --> ATE0^M > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: <-- ATE0 > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: --> ATI^M > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: <-- 332 > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: found string <332>, > using modem definition <Multitech> > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: --> AT+CSMS=?^M > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: <-- +CSMS: (0,1) > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:41 [22525] [6] INFO: AT2[multic1]: Phase 2+ is supported > 2016-10-20 17:23:41 [22525] [6] INFO: AT2[multic1]: Closing device > 2016-10-20 17:23:41 [22525] [6] INFO: AT2[multic1]: opening device > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: device opened. Telnet > mode = 0 > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: device opened > 2016-10-20 17:23:41 [22525] [6] INFO: AT2[multic1]: Logging in > 2016-10-20 17:23:41 [22525] [6] INFO: AT2[multic1]: init device > 2016-10-20 17:23:41 [22525] [6] INFO: AT2[multic1]: speed set to 115200 > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: --> ATZ^M > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:41 [22525] [6] DEBUG: AT2[multic1]: --> AT^M > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- AT > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: --> AT&F^M > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- AT&F > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: --> ATE0^M > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- ATE0 > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: --> AT+IFC=2,2^M > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: --> AT+CPIN?^M > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- +CPIN: READY > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: --> AT+CSCA=" > +33660003000 <+33%206%2060%2000%2030%2000>"^M > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: --> AT+CMGF=0^M > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: --> AT+CSMS=?^M > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: --> > AT+CSQ;+CGDCONT=1,"IP","mmsbouygtel.com";+CGSMS=2;+CNMI=2,2, > 0,1,0;+CPMS="ME","ME","ME";#SGACTCFG=1,3,200^M > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- +CSMS: (0,1) > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:23:42 [22525] [6] INFO: AT2[multic1]: AT SMSC successfully > opened. > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- +CSQ: 12,0 > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- +CPMS: > "ME",100,100,"ME",100,100,"ME",100,100 > 2016-10-20 17:23:42 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:27:23 [22525] [6] DEBUG: AT2[multic1]: TP-Validity-Period: > 24.0 hours > 2016-10-20 17:27:23 [22525] [6] DEBUG: AT2[multic1]: --> AT+CMGS=154^M > 2016-10-20 17:27:23 [22525] [6] DEBUG: AT2[multic1]: <-- > 2016-10-20 17:27:23 [22525] [6] DEBUG: AT2[multic1]: <-- > > 2016-10-20 17:27:23 [22525] [6] DEBUG: AT2[multic1]: send command status: 1 > 2016-10-20 17:27:23 [22525] [6] DEBUG: AT2[multic1]: --> > 0071000B913387237263F70008A78C0500030003010050006F0073007400 > 65002000E000200070006F007500720076006F0069007200200070006F00 > 75007200200075006E002000320034006800200073007500720020003200 > 340020006300680065007A0020003100200070006500720073006F006E00 > 6E0065002000E2006700E9006500200064006F006D006900630069006C006900E90065 > 2016-10-20 17:27:23 [22525] [6] DEBUG: AT2[multic1]: --> ^Z > 2016-10-20 17:27:25 [22525] [6] DEBUG: AT2[multic1]: <-- +CMGS: 26 > 2016-10-20 17:27:25 [22525] [6] DEBUG: AT2[multic1]: <-- OK > 2016-10-20 17:27:25 [22525] [6] DEBUG: AT2[multic1]: send command status: 0 > 2016-10-20 17:27:25 [22525] [6] DEBUG: DLR[internal]: Adding DLR > smsc=multic1, ts=26, src=1234, dst=+33783227367 > <+33%207%2083%2022%2073%2067>, mask=31, boxc= > 2016-10-20 17:27:26 [22525] [6] DEBUG: AT2[multic1]: <-- +CDS: 25 > 2016-10-20 17:27:26 [22525] [6] DEBUG: AT2[multic1]: <-- > 07913366003000F0060C0B913387237263F7610102715245806101027152558000 > 2016-10-20 17:27:26 [22525] [6] DEBUG: AT2[multic1]: received message from > SMSC: +33660003000 <+33%206%2060%2000%2030%2000> > 2016-10-20 17:27:26 [22525] [6] DEBUG: AT2[multic1]: got STATUS-REPORT for > message <12>: > 2016-10-20 17:27:26 [22525] [6] DEBUG: AT2[multic1]: Numeric receiver > (international) <+33783227367 <+33%207%2083%2022%2073%2067>> > 2016-10-20 17:27:26 [22525] [6] DEBUG: DLR[internal]: Looking for DLR > smsc=multic1, ts=12, dst=+33783227367 <+33%207%2083%2022%2073%2067>, > type=1 > 2016-10-20 17:27:26 [22525] [6] WARNING: DLR[internal]: DLR from > SMSC<multic1> for DST<+33783227367 <+33%207%2083%2022%2073%2067>> not > found. > 2016-10-20 17:27:26 [22525] [6] DEBUG: AT2[multic1]: Received delivery > notification but can't find that ID in the DLR storage > 2016-10-20 17:27:26 [22525] [6] DEBUG: System error 1: Operation not > permitted > 2016-10-20 17:27:26 [22525] [6] ERROR: AT2[multic1]: could not decode PDU > to a message. > > I've read that there was this problem on the 1.4 version, but I'm on the > 1.5... > > Any idea of the problem ? > > Thank you, > > > *Hakim BIMAZGANE* > *Lead Développeur* > > Vit*alliance* > * Service professionnel d'aide à domicile* >
