Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Issues with multi-part SMS messages (Type 2) #164

Closed
biuklija opened this issue Dec 21, 2022 · 9 comments
Closed

Issues with multi-part SMS messages (Type 2) #164

biuklija opened this issue Dec 21, 2022 · 9 comments
Labels
question Further information is requested

Comments

@biuklija
Copy link

The issue is present on a B525s-23a, I can't check for sure if other devices have the same problem.

In some cases my provider sends a multi-part message (consisting of two or more texts) and it takes a few seconds for them to all arrive. If I happen to poll for new messages during those few seconds while parts are incoming and happen to mark any of the parts as read, the message is never combined and parts remain under different indexes, usually completely out of order.

All of the parts are categorised as 'SmsType': '2', which I assume is multi-part.

I've tried to replicate the issue by sending my own multi-part messages, but these always came at the same time and were properly combined.
Is this something we could prevent? Does the original API have a flag or status which would indicate that the original multi-part message has not yet been recombined?

@Salamek Salamek added the question Further information is requested label Dec 22, 2022
@Salamek
Copy link
Owner

Salamek commented Dec 22, 2022

Hmm i don't really know to be frank i have never tested this at all, how are messages marked as read? Only by polling them? Does Web UI has same issues? (we cant possibly test for that when we can't reproduce the error by our self)

First we need a reliable way how to reproduce this issue so some experimenting can be done...

@biuklija
Copy link
Author

biuklija commented Dec 22, 2022

Okay, so I've managed to reproduce the expected behaviour, but not issue. I've polled for new SMS messages every 100 milliseconds and this is what happens - messages are assigned indexes as they arrive and once the message is recombined, the parts are deleted/de-indexed and only the complete message is available, indexed as the message which first arrived. This is a truncated log, I've excluded any repeated messages. In this instance, I haven't been marking messages as read.

2022-12-22 17:58:24 Message 1: This is a very long text message that spans multiple SMS messages, now for some padding.......................................................
{'Smstat': '0', 'Index': '40017', 'Phone': '+XXXXXXXXXXX', 'Content': 'Message 1: This is a very long text message that spans multiple SMS messages, now for some padding.......................................................', 'Date': '2022-12-22 17:58:22', 'Sca': None, 'SaveType': '0', 'Priority': '0', 'SmsType': '2'}
2022-12-22 17:58:24 ....Message 2: This is a very long text message that spans multiple SMS messages, now for some padding...................................................
{'Smstat': '0', 'Index': '40018', 'Phone': '+XXXXXXXXXXX', 'Content': '....Message 2: This is a very long text message that spans multiple SMS messages, now for some padding...................................................', 'Date': '2022-12-22 17:58:22', 'Sca': None, 'SaveType': '0', 'Priority': '0', 'SmsType': '2'}
2022-12-22 17:58:25 ........Message 3: This is a very long text message that spans multiple SMS messages, now for some padding...............................................
{'Smstat': '0', 'Index': '40019', 'Phone': '+XXXXXXXXXXX', 'Content': '........Message 3: This is a very long text message that spans multiple SMS messages, now for some padding...............................................', 'Date': '2022-12-22 17:58:23', 'Sca': None, 'SaveType': '0', 'Priority': '0', 'SmsType': '2'}
2022-12-22 17:58:25 ............Message 4: This is a very long text message that spans multiple SMS messages, now for some padding...........................................
{'Smstat': '0', 'Index': '40025', 'Phone': '+XXXXXXXXXXX', 'Content': '............Message 4: This is a very long text message that spans multiple SMS messages, now for some padding...........................................', 'Date': '2022-12-22 17:58:23', 'Sca': None, 'SaveType': '0', 'Priority': '0', 'SmsType': '2'}
2022-12-22 17:58:25 Message 1: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................Message 2: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................Message 3: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................Message 4: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................
{'Smstat': '0', 'Index': '40017', 'Phone': '+XXXXXXXXXXX', 'Content': 'Message 1: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................Message 2: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................Message 3: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................Message 4: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................', 'Date': '2022-12-22 17:58:23', 'Sca': None, 'SaveType': '0', 'Priority': '0', 'SmsType': '2'}

On my second attempt, I've tried marking the parts as read as soon as they arrive. All the parts were marked as read (including the first part)), but when they were recombined the whole message was "unread".

2022-12-22 18:01:10 Message 1: This is a very long text message that spans multiple SMS messages, now for some padding.......................................................
{'Smstat': '0', 'Index': '40018', 'Phone': '+XXXXXXXXXXX', 'Content': 'Message 1: This is a very long text message that spans multiple SMS messages, now for some padding.......................................................', 'Date': '2022-12-22 18:01:08', 'Sca': None, 'SaveType': '0', 'Priority': '0', 'SmsType': '2'}
2022-12-22 18:01:10 ....Message 2: This is a very long text message that spans multiple SMS messages, now for some padding...................................................
{'Smstat': '0', 'Index': '40019', 'Phone': '+XXXXXXXXXXX', 'Content': '....Message 2: This is a very long text message that spans multiple SMS messages, now for some padding...................................................', 'Date': '2022-12-22 18:01:08', 'Sca': None, 'SaveType': '0', 'Priority': '0', 'SmsType': '2'}
2022-12-22 18:01:11 ........Message 3: This is a very long text message that spans multiple SMS messages, now for some padding...............................................
{'Smstat': '0', 'Index': '40025', 'Phone': '+XXXXXXXXXXX', 'Content': '........Message 3: This is a very long text message that spans multiple SMS messages, now for some padding...............................................', 'Date': '2022-12-22 18:01:08', 'Sca': None, 'SaveType': '0', 'Priority': '0', 'SmsType': '2'}
2022-12-22 18:01:11 ............Message 4: This is a very long text message that spans multiple SMS messages, now for some padding...........................................
{'Smstat': '0', 'Index': '40026', 'Phone': '+XXXXXXXXXXX', 'Content': '............Message 4: This is a very long text message that spans multiple SMS messages, now for some padding...........................................', 'Date': '2022-12-22 18:01:09', 'Sca': None, 'SaveType': '0', 'Priority': '0', 'SmsType': '2'}
2022-12-22 18:01:11 Message 1: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................Message 2: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................Message 3: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................Message 4: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................
{'Smstat': '0', 'Index': '40018', 'Phone': '+XXXXXXXXXXX', 'Content': 'Message 1: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................Message 2: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................Message 3: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................Message 4: This is a very long text message that spans multiple SMS messages, now for some padding...........................................................', 'Date': '2022-12-22 18:01:09', 'Sca': None, 'SaveType': '0', 'Priority': '0', 'SmsType': '2'}

It is possible that the issue I've raised only occurs if you mark certain parts as read as they arrive, instead of all of them or none of them, possibly because of the indexes. My old script based on the relay example did this, as it polled only one unread text at a time. I'm not sure how to reproduce the bug.

@Salamek
Copy link
Owner

Salamek commented Dec 23, 2022

I have put some thought into this, and i think this is race-condition in huawei firmware... Since it would be very hard to put a modem into this situation when using official web UI (there is very small chance that user using official web UI will be able to read one SMS of multi part SMS before it is able to recombine correctly).

So this is technically 'wontfix' since there is nothing i can do with huawei FW, BUT i think i have also came with hack how to prevent this from happening when using the huawei-lte-api when polling SMS.

Lets say we have this untested code as a example of usage that will "trigger" this race-condition:

from huawei_lte_api.Session import Session
from huawei_lte_api.User import UserSession
from huawei_lte_api.Sms import Sms
from huawei_lte_api.enums.sms import BoxTypeEnum

while True:
    try:
        with Session('http://192.168.8.1') as session:
            with UserSession('admin', 'admin'):
                sms = Sms(session)
                fetched_sms = sms.get_sms_list(1, BoxTypeEnum.LOCAL_INBOX, 1, 0, 0, 1)

                # Check if we have any messages
                if not fetched_sms.get('Messages'):
                    continue

                message = fetched_sms.get('Messages', {}).get('Message', {})

                message_index = int(message.get('Index'))
                message_stat = int(message.get('Smstat'))
                message_type = int(message.get('SmsType'))
                message_content = message.get('Content')


                # Skip read message
                if message_stat == 1:
                    continue

                # Process our SMS
                print('You have new SMS:')
                print(message_content)


                # mark message read
                sms.set_read(message_index)
    except Exception as e:
        print('Something failed: {}'.format(e))

    time.sleep(60) # Check every minute

And here are changes (untested) to ~prevent that race condition by check if message is type==2 if is type 2 ignore it until is older then specified type (60 seconds) that should provide enough time for all parts to be received and merged:

import datetime
import aniso8601
from huawei_lte_api.Session import Session
from huawei_lte_api.User import UserSession
from huawei_lte_api.Sms import Sms
from huawei_lte_api.enums.sms import BoxTypeEnum

while True:
    now = datetime.datetime.now()
    try:
        with Session('http://192.168.8.1') as session:
            with UserSession('admin', 'admin'):
                sms = Sms(session)
                fetched_sms = sms.get_sms_list(1, BoxTypeEnum.LOCAL_INBOX, 1, 0, 0, 1)

                # Check if we have any messages
                if not fetched_sms.get('Messages'):
                    continue

                message = fetched_sms.get('Messages', {}).get('Message', {})

                message_index = int(message.get('Index'))
                message_date = aniso8601.parse_datetime(message.get('Date'))
                message_stat = int(message.get('Smstat'))
                message_type = int(message.get('SmsType'))
                message_content = message.get('Content')


                # Skip read message
                if message_stat == 1:
                    continue

                # Check if message is possibly multipart,
                # if it is ignore it if is younger then 60 seconds
                # This way we provide the router with enough time to receive all possible parts and do correct rebuild
                if message_type == 2 and message_date + datetime.timedelta(seconds=60) > now:
                    continue


                # Process our SMS
                print('You have new SMS:')
                print(message_content)


                # mark message read
                sms.set_read(message_index)
    except Exception as e:
        print('Something failed: {}'.format(e))

    time.sleep(60) # Check every minute

@biuklija
Copy link
Author

I've figured as much, it's a very specific issue and I assume the firmware itself has similar code which will hold off triggering the "new message" flag until the message is recombined. That's why the the Type flag is there in the first place, I suppose.
I'll test out your proposed solution in coming days and report back. It wouldn't hurt to leave a note about this somewhere in the documentation.

@biuklija
Copy link
Author

Proposed solution works as intended, the only issue is that aniso8601.parse_datetime expects a "T" delimiter, whereas the API provides a space.

message_date = aniso8601.parse_datetime(msg_text.get('Date'), delimiter=' ')

@Salamek
Copy link
Owner

Salamek commented Dec 25, 2022

Yea i have expected there may be some small issue in datetime parsing.... hmm i think i can use simple datetime.strptime to parse this datetime format, it will save me one dependency

@Salamek
Copy link
Owner

Salamek commented Dec 25, 2022

Also is not 60 seconds too much? what delay between parted SMS did you observe?

@biuklija
Copy link
Author

60 seconds is way too much in my opinion. I've used 5 seconds this time around, it was more than enough. You can see from my earlier tests that it took less than two seconds for my four-part SMS message to arrive (first part arrived at 17:58:24, fully recombined at 17:58:25 and I waited 500 ms between polls, if memory serves). It probably depends on the length and network conditions, but I doubt it would ever take more than 5 seconds.

@Salamek
Copy link
Owner

Salamek commented Dec 25, 2022

1.6.10 Implements new method Sms.get_messages that implements this fix and also yields new dataclass Message with SMS info

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
question Further information is requested
Projects
None yet
Development

No branches or pull requests

2 participants