Strange situation at sending

Strange situation at sending SearchSearch
Author Message
Alexandre
Frequent Contributor
Username: Alexd

Post Number: 52
Registered: 01-2008
Posted on Thursday, May 13, 2010 - 01:23 pm:   

Has noticed lately very strange thing at sending, I have sent the message consisting of 3 segments,
in SMSOUT log I see records:

2010-05-13 14:08:04, SAR-+phone_number-4e626dae-3-1.req, 192.168.0.2, +phone_number, OK - SMPP - GATEWAY, SubmitUser=login; Sender=Test1; SMSCMsgId=103702511; DCS=8; UDH=050003ED0301; Text = "Text of message"
2010-05-13 14:08:04, SAR-+phone_number-4e626dae-3-2.req, 192.168.0.2, +phone_number, OK - SMPP - GATEWAY, SubmitUser=login; Sender=Test1; SMSCMsgId=103702513; DCS=8; UDH=050003ED0302; Text = "Text of message"
2010-05-13 14:08:04, SAR-+phone_number-4e626dae-3-3.req, 192.168.0.2, +phone_number, OK - SMPP - GATEWAY, SubmitUser=login; Sender=Test1; SMSCMsgId=103702514; DCS=8; UDH=050003ED0303; Text = "Text of message"

In SMSIN log I see:

2010-05-13 14:08:20, +phone_number, SMPP - GATEWAY, Text = "ID:SAR-+phone_number-4e626dae-3-1 sub:0 dlvrd:0 submit date:1005131403 done date:1005131403 stat:DELIVRD err:0 Text: netwerr:0x030000"; Recip=Test1; SMSCRECEIPTMSGID=SAR-+phone_number-4e626dae-3-1; SMSCReceiptMsgIdOrig=103702511
2010-05-13 14:08:37, +phone_number, SMPP - GATEWAY, Text = "ID:SAR-+phone_number-4e626dae-3-2 sub:0 dlvrd:0 submit date:1005131403 done date:1005131404 stat:DELIVRD err:0 Text: netwerr:0x030000"; Recip=Test1; SMSCRECEIPTMSGID=SAR-+phone_number-4e626dae-3-2; SMSCReceiptMsgIdOrig=103702513
2010-05-13 14:08:38, +phone_number, SMPP - GATEWAY, Text = "ID:SAR-+phone_number-4e626dae-3-3 sub:0 dlvrd:0 submit date:1005131403 done date:1005131404 stat:DELIVRD err:0 Text: netwerr:0x030000"; Recip=Test1; SMSCRECEIPTMSGID=SAR-+phone_number-4e626dae-3-3; SMSCReceiptMsgIdOrig=103702514

I.e. the message Are delivered the addressee, but during too time I have noticed still records in SMSOUT log,
on the same phone only NowSMS id +1:

2010-05-13 14:08:04, SAR-+phone_number-4e626daf-3-1.req, 192.168.0.2, +phone_number, ERROR: submit_sm or submit_multi failed - ESME_RSUBMITFAIL (0x45) - SMPP - GATEWAY, SubmitUser=login; Sender=Test1; DCS=8; UDH=050003ED0301; Text = "Text of message"
2010-05-13 14:08:04, SAR-+phone_number-4e626daf-3-2.req, 192.168.0.2, +phone_number, ERROR: submit_sm or submit_multi failed - ESME_RSUBMITFAIL (0x45) - SMPP - GATEWAY, SubmitUser=login; Sender=Test1; DCS=8; UDH=050003ED0302; Text = "Text of message"
2010-05-13 14:08:04, SAR-+phone_number-4e626daf-3-3.req, 192.168.0.2, +phone_number, ERROR: submit_sm or submit_multi failed - ESME_RSUBMITFAIL (0x45) - SMPP - GATEWAY, SubmitUser=login; Sender=Test1; DCS=8; UDH=050003ED0303; Text = "Text of message"

UDH same as well as in the first case and sending time same though I sent once this message.
And as UDH should differ if NowSMS duplicated messages?

As in SMSIN log I see the report on delivery under this second "strange" message:

2010-05-13 14:08:04, +phone_number, SMPP - GATEWAY, Text = "ID:SAR-+phone_number-4e626daf-3-1 sub:001 dlvrd:000 submit date:1005131402 done date:1005131408 stat:REJECTD err:045 text:0412002004470430043"; Recip=Test1; SMSCRECEIPTMSGID=SAR-+phone_number-4e626daf-3-1; SMSCRECEIPTMSGIDORIG=SAR-+phone_number-4e626daf-3-1
2010-05-13 14:08:04, +phone_number, SMPP - GATEWAY, Text = "ID:SAR-+phone_number-4e626daf-3-2 sub:001 dlvrd:000 submit date:1005131402 done date:1005131408 stat:REJECTD err:045 text:002004340435043D044"; Recip=Test1; SMSCRECEIPTMSGID=SAR-+phone_number-4e626daf-3-2; SMSCRECEIPTMSGIDORIG=SAR-+phone_number-4e626daf-3-2
2010-05-13 14:08:04, +phone_number, SMPP - GATEWAY, Text = "ID:SAR-+phone_number-4e626daf-3-3 sub:001 dlvrd:000 submit date:1005131402 done date:1005131408 stat:REJECTD err:045 text:043404300440043E043"; Recip=Test1; SMSCRECEIPTMSGID=SAR-+phone_number-4e626daf-3-3; SMSCRECEIPTMSGIDORIG=SAR-+phone_number-4e626daf-3-3

How there is such situation? Than duplication of messages (though NowSMSID different and UDH identical) is caused?
Des - NowSMS Support
Board Administrator
Username: Desosms

Post Number: 2109
Registered: 08-2008
Posted on Thursday, May 13, 2010 - 02:43 pm:   

Hi Alexandre,

How did these messages get submitted into NowSMS?

SMPP client?

HTTP client?

I'm guessing HTTP, because I don't think the longer ID happens with SMPP.

I believe this situation would occur if the message was submitted to the same recipient listed more than once in the recipient list. The UDH is the same for each recipient, but the message ID differs per recipient.

The SMSWEB log should show some more about the submission. I suspect the message was addressed to multiple recipients, with one of the recipients listed twice.

--
Des
NowSMS Support
Alexandre
Frequent Contributor
Username: Alexd

Post Number: 53
Registered: 01-2008
Posted on Thursday, May 13, 2010 - 02:53 pm:   

Sent by SMPP client
Des - NowSMS Support
Board Administrator
Username: Desosms

Post Number: 2117
Registered: 08-2008
Posted on Thursday, May 13, 2010 - 05:04 pm:   

Are you sure that an SMPP client submitted these messages?

The message ID format "SAR-+phone_number-4e626daf-3-3" suggests that an HTTP client generated this message. If an SMPP client generated the message, the UDH segment reference number would be used in place of "4e626daf", and it could not be that large.

--
Des
NowSMS Support
Alexandre
Frequent Contributor
Username: Alexd

Post Number: 54
Registered: 01-2008
Posted on Friday, May 14, 2010 - 07:44 am:   

Ahhh sorry u r right that sms was sent by http, but in recepient list was only one number, by the way, that situation with duplicate was when sms sent via SMPP client too.
Des - NowSMS Support
Board Administrator
Username: Desosms

Post Number: 2122
Registered: 08-2008
Posted on Friday, May 14, 2010 - 09:04 pm:   

I'd need to see some more detailed logs, and more information about the overall configuration.

In the above case, I think you'll find the SMSWEB log file showing the message being submitted twice.

If it happens all the time, then generate an SMSDEBUG.LOG showing it happening. Or at least start with logs like above showing a transaction from an SMPP client.
Alexandre
Frequent Contributor
Username: Alexd

Post Number: 55
Registered: 01-2008
Posted on Monday, May 17, 2010 - 08:55 am:   

I have noticed that the given duplication arises when there is an error:
NowSMS Error Report. SMS message could not be sent to +XXXXX, ERROR: submit_sm or submit_multi failed - ESME_RSUBMITFAIL (0x45)

He writes the given error in SMSOUT log, but after some seconds the message goes normally on the same number.

Whether it can is connected with any antispam (antiflood) filters on SMSC? Whether it can be connected what NowSMS tries to send the message once again if there is such error (0x45)?

I cannot give more the entire account as it arises spontaneously.
Alexandre
Frequent Contributor
Username: Alexd

Post Number: 56
Registered: 01-2008
Posted on Monday, May 17, 2010 - 09:02 am:   

If it will be not clear, I всеп will try to include SMSDEBUG log and to catch the given situation.
Alexandre
Frequent Contributor
Username: Alexd

Post Number: 57
Registered: 01-2008
Posted on Monday, May 17, 2010 - 09:52 am:   

And one more moment if SMSC at once returns: ESME_RSUBMITFAIL (0x45) that why NowSMS nevertheless sends this message? As in SMSIN log I see delivery_sm a kind:... submit date:1005171246 done date:1005171246 stat:REJECTD err:045....
Des - NowSMS Support
Board Administrator
Username: Desosms

Post Number: 2129
Registered: 08-2008
Posted on Monday, May 17, 2010 - 06:01 pm:   

Alexandre,

An SMSDEBUG.LOG would definitely add some clarification to what exactly is happening.

What I can tell you is that ESME_RSUBMITFAIL (0x45) is not the source of duplication.

The SMSIN entry that includes the text "REJECTD err:045" is being generated by NowSMS, and is not actually coming from the upstream SMSC. If an upstream SMSC rejects a message, and a delivery receipt was requested for the message, then NowSMS generates a non-delivery receipt back to the sender when the message is rejected.

The upstream SMSC may be rejecting it because it believes it is a duplicate.

What I am saying is that this is not the point at which the message gets duplicated.

In your first posting, it appears that the message was received twice via the web interface, because I see two separate IDs assigned to the message. The SMSWEB-yyyymmdd.LOG logs when messages are submitted for outbound queueing, whether submitted via HTTP or SMPP. I expect that you will see that these "duplicate" messages appear to be getting submitted more than once.

--
Des
NowSMS Support
Alexandre
Frequent Contributor
Username: Alexd

Post Number: 58
Registered: 01-2008
Posted on Tuesday, May 18, 2010 - 09:33 am:   

Here is part of smsdebug.log

In SMPPDEBUG log I see that the client sent twice probably because NowSMS has not returned an error "submit multi failed..."
I so understand the given error not critical and consequently in SMPP it is not transferred to session, whether probably somehow to adjust NowSMS that any final status came back?

And one more moment...in SMSDEBUG log i see only one SMPPServerReceiveMessageCallback: inbound message
text/plain
smsdebug_part.txt (9.1 k)
Des - NowSMS Support
Board Administrator
Username: Desosms

Post Number: 2134
Registered: 08-2008
Posted on Tuesday, May 18, 2010 - 08:02 pm:   

Hi Alexandre,

I'm not trying to be difficult. However, I only have a very limited view of what is happening on your system.

From an end user perspective, what happened in this sequence of events that are described by this log snapshot?

Were any messages received by the end user?

I only see NowSMS receive a single message from an SMPP client named "test_login".

NowSMS tries to submit that message to the upstream SMSC, and the upstream SMSC returns error 0x45, ESME_RSUBMITFAIL.

So NowSMS generates a non-delivery report back to the sending client account (test_login).

That's all I see.

If the message was sent twice, and accepted once by the upstream SMSC ... none of that appears in this log snapshot.

--
Des
NowSMS Support
Alexandre
Frequent Contributor
Username: Alexd

Post Number: 59
Registered: 01-2008
Posted on Wednesday, May 19, 2010 - 08:06 am:   

In my the first the message in this theme, I have given an example, when the client sends one message and it passes but for the unknown reasons one more is created with another MessageID, and SMSC returns an error "submit multi failed....". Lately many clients complain that they receive from NowSMS an error: "0x00000045 ESME_RSUBMITFAIL Submitting message has failed" though they send one message. I and have not understood, when NowSMS receives this error, he tries to redirect automatically? Or he creates notification (REJECTED) and does not do repeated sending?

Whether this all can is connected with parametre SMSCSendLimit or WindowSize? When NowSMS tries to send faster than it is possible on SMSC.
Des - NowSMS Support
Board Administrator
Username: Desosms

Post Number: 2139
Registered: 08-2008
Posted on Wednesday, May 19, 2010 - 04:53 pm:   

Hi Alexandre,

Let me address your questions directly to try to avoid further confusion.


quote:

In my the first the message in this theme, I have given an example, when the client sends one message and it passes but for the unknown reasons one more is created with another MessageID, and SMSC returns an error "submit multi failed....".




Correct. However, this is not what happens in the sequence that is shown in the debug log that you posted.

The debug log shows a message being submitted. The upstream SMSC returns ESME_RSUBMITFAIL. A non-delivery notification is sent back to the original sender.

There is no evidence or suggestion that a duplicate message was created.

Therefore, the debug log provides no insight on the suspected message duplication problem. It only shows a message being rejected by the upstream SMSC with error code ESME_RSUBMITFAIL, which I never did question.


quote:

Lately many clients complain that they receive from NowSMS an error: "0x00000045 ESME_RSUBMITFAIL Submitting message has failed" though they send one message.

Whether this all can is connected with parametre SMSCSendLimit or WindowSize? When NowSMS tries to send faster than it is possible on SMSC.




This is a good question.

It is not clear why the provider is rejecting the message with ESME_RSUBMITFAIL.

Unfortunately, only your provider can tell you for certain.

However, we can look for patterns and make educated guesses.

It is possible that the SMSC is rejecting messages because they are being submitted faster than the SMSC allows. Normally, I would expect to see ESME_RTHROTTLED or possibly ESME_RMSGQFUL if this were the case.

However, there are many different SMSC implementations, and it is possible that this one may return ESME_RSUBMITFAIL.

It would be worth trying to set an SMSCSendLimit to limit sending speed on the connection, and possibly even disabling async mode windowing, as a test to see if that reduces or eliminates these errors.


quote:

I and have not understood, when NowSMS receives this error, he tries to redirect automatically? Or he creates notification (REJECTED) and does not do repeated sending?




This is a better question (... because I can answer it with certainty).

When NowSMS generates the non-delivery notification (REJECTED), it is done processing the message. No further retries are attempted.

The fact that you are asking this question raises a potential configuration issue.

By default, if NowSMS receives an ESME_RSUBMITFAIL response, it is going to retry the message. It is not going to give up after one attempt. (And I would be curious if the retries return the same error, or if eventually the message is accepted.)

I suspect that you have disabled or limited retries in your configuration. Is this the case?

The following link explains how NowSMS handles different SMPP error codes, and retry handling:

http://blog.nowsms.com/2007/06/smpp-error-code-handling-in-nowsms.html

--
Des
NowSMS Support
Alexandre
Frequent Contributor
Username: Alexd

Post Number: 60
Registered: 01-2008
Posted on Thursday, May 20, 2010 - 01:43 pm:   

Ok..problem resolved :-) thanks.