Comments (13)
I'm not sure there is a bug. We do not guarantee that each message will be individually acknowledged. For instance, if "read" is ack-ed for seq=45, that mean all messages prior to seq=45 are also read and received even if there was no ack for seq=44.
Please point me to specific gaps in your logs. What exactly was not acknowledged in your session?
from chat.
Yes, and i understand that "read" for seq 45, will mark read prior to seq 45.
The issue is that "read" or even "recv"(sometimes, not in this case) is not being marked for seq 45(just an example) for one of the user(because of not receiving info msg, but note sent by peer user).
If you see in the logs, of client1(who is facing this bug),
- has not received any info:read, but only info:recv 5 times
- client2 has sent note:read upto seq:45
- server logs also confirm to this that server has also not sent info:read:m8BcygGayyo(client1) but only info:recv
This issue is very easily replicable on sandbox.tinode.co, just get two users, and let them send messages at fast pace, one of them will stop receiving info:read/recv(and ui will show only double/single ticks, and not blue ticks even though other has subscribed to topic and marked note).
from chat.
I'm looking at this part of your server log (I removed entries unrelated to seq=45)
I2023/05/31 08:20:58.767652 out: '{"data":{"topic":"usrMQHA4oE6F0E","from":"usrMQHA4oE6F0E","ts":"2023-05-31T08:20:55.881Z","seq":45,"content":"re"}}' sid='83MgEyejDvU' uid='m8BcygGayyo'
I2023/05/31 08:20:58.954776 in: '{"note":{"topic":"usrMQHA4oE6F0E","what":"recv","seq":45}}' sid='83MgEyejDvU' uid='m8BcygGayyo'
I2023/05/31 08:20:58.966120 in: '{"note":{"topic":"usrm8BcygGayyo","what":"recv","seq":45}}' sid='xRWQedhRy7k' uid='MQHA4oE6F0E'
I2023/05/31 08:20:59.061015 out: '{"info":{"topic":"usrm8BcygGayyo","from":"usrm8BcygGayyo","what":"recv","seq":45}}' sid='xRWQedhRy7k' uid='MQHA4oE6F0E'
I2023/05/31 08:20:59.292205 in: '{"note":{"topic":"usrMQHA4oE6F0E","what":"read","seq":45}}' sid='83MgEyejDvU' uid='m8BcygGayyo'
I2023/05/31 08:20:59.365452 out: '{"info":{"topic":"usrm8BcygGayyo","from":"usrm8BcygGayyo","what":"read","seq":45}}' sid='xRWQedhRy7k' uid='MQHA4oE6F0E'
Where exactly do you see the problem?
from chat.
Please show me the part of the logs which illustrates the problem. Or list the line numbers in the attached logs.
from chat.
I'm looking at this part of your server log (I removed entries unrelated to seq=45)
I2023/05/31 08:20:58.767652 out: '{"data":{"topic":"usrMQHA4oE6F0E","from":"usrMQHA4oE6F0E","ts":"2023-05-31T08:20:55.881Z","seq":45,"content":"re"}}' sid='83MgEyejDvU' uid='m8BcygGayyo' I2023/05/31 08:20:58.954776 in: '{"note":{"topic":"usrMQHA4oE6F0E","what":"recv","seq":45}}' sid='83MgEyejDvU' uid='m8BcygGayyo' I2023/05/31 08:20:58.966120 in: '{"note":{"topic":"usrm8BcygGayyo","what":"recv","seq":45}}' sid='xRWQedhRy7k' uid='MQHA4oE6F0E' I2023/05/31 08:20:59.061015 out: '{"info":{"topic":"usrm8BcygGayyo","from":"usrm8BcygGayyo","what":"recv","seq":45}}' sid='xRWQedhRy7k' uid='MQHA4oE6F0E' I2023/05/31 08:20:59.292205 in: '{"note":{"topic":"usrMQHA4oE6F0E","what":"read","seq":45}}' sid='83MgEyejDvU' uid='m8BcygGayyo' I2023/05/31 08:20:59.365452 out: '{"info":{"topic":"usrm8BcygGayyo","from":"usrm8BcygGayyo","what":"read","seq":45}}' sid='xRWQedhRy7k' uid='MQHA4oE6F0E'
Where exactly do you see the problem?
A: session:-xRWQedhRy7k
, user:-MQHA4oE6F0E
B: session:-83MgEyejDvU
, user:-m8BcygGayyo
Info:read is only sent to session:A
, user:A
The bug is with session:B
, user:B
Server has not sent any info:read to session:B
, user:B
. This is the problem.
user:B
's last pub message has id:91504
(line:144), seqId:42
(line:199)
user:A
marked recv:seq:42 (line:203), read:seq:43 (line:211)
Clearly, A
has marked seq:43 as read (meaning 42 should also be read, sent by B
), but server has not sent info:read:42 to B
. There is not a single info:read sent to B
, all info:read were sent to A
. Hence B
has not marked them as read (and stuck at recv status, i.e. double-ticks and not blue ticks)
from chat.
In line 218 server notifies user B
that user A
received message seq=40. It's quite possible that you simply overwhelmed the server and the messages were backed up. If you wait long enough the notification for 42 will be sent as well.
I2023/05/31 08:20:58.840424 out: '{"info":{"topic":"usrMQHA4oE6F0E","from":"usrMQHA4oE6F0E","what":"recv","seq":40}}' sid='83MgEyejDvU' uid='m8BcygGayyo'
from chat.
In line 218 server notifies user
B
that userA
received message seq=40. It's quite possible that you simply overwhelmed the server and the messages were backed up. If you wait long enough the notification for 42 will be sent as well.I2023/05/31 08:20:58.840424 out: '{"info":{"topic":"usrMQHA4oE6F0E","from":"usrMQHA4oE6F0E","what":"recv","seq":40}}' sid='83MgEyejDvU' uid='m8BcygGayyo'
I think you are missing point. The point i am trying to convey you is that server is not sending "read"(emphasis) for messages sent by B and marked as "read" by A. Server will not send info:read to B until another message is sent by B->A and A marks it as read(by sending note) -> and server issues a info:read to B, no matter wait. I get it that server is overwhelmed because of too many read/recv from both sides, but that is where bug lies. This is just a single p2p topic, and we are using standalone 4 core machine, and as i said earlier too this is replicable on sandbox.tinode.co .
Ok, tested just now on sandbox.tinode.co
client1: web
client2: tindroid
client1 didn;t receive a single info:read.
I waited for 2 mins, as you said that server might need time, but it didn't send any info. Then client1 sent pub(id:99067), and in response client2 issues note:read and server issues info:read to client1.(this is success case, but client1 was stuck at recv until it sent another message, take example if client1 sent 2 messages on day1, and client 2 has ack-ed them also(sent note:read), but server didn't sent info:read to client1, now only if client1 sends another message on day2(lets say), only then it will know that client2 had already seen his day1 messages)
info-missing-sandbox-tinode-client.zip
I think i have tried my best to explain you the problem.
Thanks
from chat.
I think you are missing point.
It's quite possible that I'm missing the point because I'm unable to see the problem in the attached logs. Or you are unable to clearly demonstrate it.
You said in context of message 42:
Server has not sent any info:read to session:B, user:B. This is the problem.
No, that is not a problem because the server did not receive note=read seq=42
from anyone, consequently it did not send info read seq=42
to any client.
The server received note read seq=43
from usrm8BcygGayyo
(line 206) and it forwarded it to usrMQHA4oE6F0E
(line 220).
It's very difficult for me to follow your reasoning. Please give me the line number where client usrXXX
sent note read seq=123
and then the server never followed with info read seq=123
to usrYYY
.
Then client1 sent pub(id:99067),
I do not see a message with id=99067 in your logs.
from chat.
Could you please clarify this so we could be on same page.
In this attachement, i have added a script which does the simulation of two users sending message to each other at same time.
-
user A and B subs to each other and send a message at same time.
-
Both of them marks it as recv and read as soon as they get {data} message.
-
In the server logs, we could see that it dropped info:read for seq:106 (meant for sess:
0b1Vfs6Gh0o
, user:IoXH4yjUJMg
) -
It only sent info:read for seq:107(to sess:
0sog3gqfjGE
, user:svxfCch7U5k
) -
And (sess:
0b1Vfs6Gh0o
, user:IoXH4yjUJMg
) is unable to determine that seq:106 message was read by (sess:0sog3gqfjGE
, user:svxfCch7U5k
) or not. -
Removing those if conditions will fix this, but this will result in a lot of info messages(for eg, in case of large group), that could have been dropped.
Thanks
from chat.
Yes, I see the problem now. Let me think about it.
from chat.
Thank you acknowledging the issue. Looking forward to it.
from chat.
Here is the underlying reason.
Read
and recv
notifications make use of the fact that messages have a sequential ID seq
. If message with seq=100
is received (or read), that means the client has also received all messages with seq<100
. Client uses {note seq=...}
to inform counterparties that the message was received or read.
If a client sends a message with seq=100
then obviously this client also received/read his own message.
And that's where the problem comes from:
- Client receives message
seq=100
- Client sends a new message
- Server receives message from step 2 and assigns
seq=101
to it, sends{ctrl}
to the client - Server marks client as having received and read all messages up to
seq=101
. - Client acks
{note read seq=100}
, server receives the ack and discards it because in step 4 client was marked as having receivedseq=101
already.
The most rational way to fix it is that if Client B
received a message from Client A
with seq=101
, then Client B
should assume that Client A
has received all messages up to seq=101
. I'm going to make these changes to the client.
from chat.
Very interesting but obvious solution, it seems.
Thanks, this has fixed the issue.
from chat.
Related Issues (20)
- [Question] External config is not working as expected HOT 2
- crash when removing a topic with RethinkDB HOT 3
- A feature request for status values. HOT 2
- error: The data couldn’t be read because it isn’t in the correct format in IOS HOT 1
- Can't initialize postgres database (does not use configured database to init) HOT 1
- Repetitive sub<->leave requests on same topic results in some leave requests with no response HOT 3
- Error starting gRPC call. HttpRequestException: No connection could be made because the target machine actively refused it. (127.0.0.1:6061) SocketException: No connection could be made because the target machine actively refused it. HOT 3
- Support S3 Compatible Storage Providers HOT 7
- External jwt token authenticator HOT 2
- Tinode not triggering password reset emails HOT 3
- NOT WORKING VIDEO CALL OTHER INTERNET HOT 1
- Cluster Not Working, Error: [ cluster: call failed two gob: unknown type id or corrupted data ] HOT 1
- In-app unread message counter does not account for deleted messages HOT 1
- How to create just a p2p topics? HOT 1
- Cannot initialize postgresql database HOT 7
- Drafty should correctly parse after fix for https://github.com/tinode/tinode-js/issues/74
- Cannot setup TLS HOT 1
- crée un script complet [removed]
- Chat
- How to deactive an account, so that they no longer login and receive new message/notification?
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from chat.