Cannot send nor receive messages

[alexolog]

When I connect to the protocol, it sends me a huge amount of data which looks like my whole conversation history. Then a large number of SyncBatch messages. Then some assertions (g_log: purple_ssl_read: assertiondata != NULL' failed`) as it writes the accounts.xml file.

Messages sent to me do not arrive.

Trying to send messages gives the following in the debug window:

(19:14:54) conversation: typed...
(19:14:55) sessionsave: saving
(19:14:55) prefs: /plugins/core/sessionsave/conversations changed, scheduling save.
(19:14:55) yahoo: frame_len: 146
(19:14:55) yahoo: got frame data: {"msg":"ChannelProtocolError","reason":"Invalid frame: List((/data(0)(0)/groupId,List(ValidationError(error.expected.jsstring,WrappedArray()))))"}
(19:14:55) yahoo: websocket closed
(19:14:55) dnsquery: Performing DNS lookup for prod.iris.yahoo.com
(19:14:55) dnsquery: IP resolved for prod.iris.yahoo.com
(19:14:55) proxy: Attempting connection to 63.250.200.45
(19:14:55) proxy: Connecting to prod.iris.yahoo.com:443 with no proxy
(19:14:55) proxy: Connection in progress
(19:14:55) proxy: Connecting to prod.iris.yahoo.com:443.
(19:14:55) proxy: Connected to prod.iris.yahoo.com:443.
(19:14:56) nss: SSL version 3.3 using 128-bit AES-GCM with 128-bit AEAD MAC
Server Auth: 2048-bit RSA, Key Exchange: 256-bit ECDHE, Compression: NULL
Cipher Suite Name: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
(19:14:56) nss: subject=CN=*.iris.yahoo.com,OU=Information Technology,O=Yahoo Inc.,L=Sunnyvale,ST=California,C=US issuer=CN=Symantec Class 3 Secure Server CA - G4,OU=Symantec Trust Network,O=Symantec Corporation,C=US
(19:14:56) nss: partial certificate chain
(19:14:56) certificate/x509/tls_cached: Starting verify for prod.iris.yahoo.com
(19:14:56) certificate/x509/tls_cached: Checking for cached cert...
(19:14:56) certificate/x509/tls_cached: ...Found cached cert
(19:14:56) nss/x509: Loading certificate from C:\Users\me\AppData\Roaming\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(19:14:56) certificate/x509/tls_cached: Peer cert matched cached
(19:14:56) nss/x509: Exporting certificate to C:\Users\me\AppData\Roaming\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(19:14:56) util: Writing file C:\Users\me\AppData\Roaming\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(19:14:56) nss: Trusting CN=*.iris.yahoo.com,OU=Information Technology,O=Yahoo Inc.,L=Sunnyvale,ST=California,C=US
(19:14:56) certificate: Successfully verified certificate for prod.iris.yahoo.com
(19:14:56) yahoo: frame_len: 52
(19:14:56) yahoo: got frame data: {"seq":178,"ack":190,"data":[],"time":1472771696062}

[EionRobb]

There's been a bunch of work recently to fix this. Can you try again with a new libyahoo-plusplus.dll download from http://eion.robbmob.com/libyahoo-plusplus.dll

[alexolog]

Thanks, I'll check it.

It would be nice to have some sort of notification that a new version is available without tracking everything that happens on git. Pidgin is used by end-users as well, not only by developers :)

[alexolog]

OK, several things:

1. When connecting to the protocol, I am getting many assertions g_log: purple_conversation_get_chat_data: assertionconv != NULL' failed(over 50) g_log: purple_status_is_online: assertion status != NULL' failed (2)

2. When connecting to the protocol, Yahoo sends a lot of buddy IDs, some of which are in active. I get duplicates and triplicates of my buddies but only one of the connections can send and receive messages. I see a difference in the data that is passed for the "active" and "dead" id, so the plugin can likely filter out the dead ones.

Interestingly, if I try to message one of the "dead" contacts via messenger.yahoo.com, it is smart enough to send the message to the corresponding "live" one.

4. The data contains information about the contact's name, icon and so on, and some of it is not used by the plugin.

5. The data contains information about the latest messages to/from the contacts, but the plugin does not appear to use it.

6. Trying to send a message to a "dead" id, produces the following error: {"msg":"ChannelProtocolError","reason":"Invalid frame: List((/data(0)(0)/groupId,List(ValidationError(error.expected.jsstring,WrappedArray()))))"}

7. Sending a message to a "live" id, results in over a 100 "SyncBatch" / "SyncAck" pairs.

I will provide a (sanitized) log on request.

[alexolog]

A buddy just messaged me. Instead of appearing under the buddy's ID, a new ID was created and added (as a group)

Those "groups" seem to be persistent and only provide the 28-character ids.

[alexolog]

It seems like it is possible to figure out which live contacts the dead contacts should be replaced with.

I have 3 contacts for the same buddy, one live and two dead. Yahoo tells me that there are 2 groups, the first contains the 1st and the 2nd contacts and the second contains the 1st and the 3rd contact, with the 1st contact being the default for both.

The contacts (sanitized):

{
    "msg": "NewEntity",
    "key": [
        "User",
        "contact id #1 (live)"
    ],
    "cn": 1,
    "userId": "contact id #1 (live)"
    "shortName": "undisclosed",
    "fullName": "undisclosed",
    "initials": "undisclosed"
}

{
    "msg": "NewEntity",
    "key": [
        "User",
        "contact id #2 (dead)"
    ],
    "cn": 1,
    "inviteIdentifier": "undisclosed",
    "fullName": "undisclosed",
    "inviteService": "ymessenger",
    "userId": "contact id #2 (dead)"
    "shortName": ""
}

{
    "msg": "NewEntity",
    "key": [
        "User",
        "contact id #3 (dead)"
    ],
    "cn": 1,
    "inviteIdentifier": "undisclosed",
    "fullName": "undisclosed",
    "inviteService": "smtp",
    "userId": "contact id #3 (dead)"
    "shortName": ""
}

The groups:

{
    "msg": "NewEntity",
    "key": [
        "Group",
        "group id #1"
    ],
    "cn": 8,
    "name": "",
    "defaultGroup": false,
    "groupId": "group id #1",
    "createdTime": nnn,
    "memberCount": 2,
    "lastItemId": "xxx",
    "defaultGroupOtherUser": [
        "User",
        "contact id #1 (live)"
    ]
}

{
    "msg": "NewEntity",
    "key": [
        "Group",
        "group id #2"
    ],
    "cn": 124,
    "name": "",
    "defaultGroup": true,
    "groupId": "group id #2",
    "createdTime": nnn,
    "memberCount": 2,
    "lastItemId": "xxx",
    "defaultGroupOtherUser": [
        "User",
        "contact id #1 (live)"
    ]
}

{
    "msg": "NewEntity",
    "key": [
        "Group",
        "group id #1",
        "members",
        "xxx"
    ],
    "cn": 2,
    "lastReadItemId": "xxx",
    "admin": true,
    "invitationState": "merged",
    "createdTime": nnn,
    "group": [
        "Group",
        "group id #1"
    ],
    "user": [
        "User",
        "contact id #2 (dead)"
    ]
}

{
    "msg": "NewEntity",
    "key": [
        "Group",
        "group id #2",
        "members",
        "xxx"
    ],
    "cn": 2,
    "lastReadItemId": "xxx",
    "admin": true,
    "invitationState": "merged",
    "createdTime": nnn,
    "group": [
        "Group",
        "group id #2"
    ],
    "user": [
        "User",
        "user id #3 (dead)"
    ]
}

Interestingly, when the 1st (live) contact sent me a message, it appeared in the conversation of the 1st group, even though I was able to concurrently converse with them in another conversation (with their user name).

Hope that helps.

[dequis]

1. When connecting to the protocol, I am getting many assertions g_log: purple_conversation_get_chat_data: assertionconv != NULL' failed(over 50) g_log: purple_status_is_online: assertion status != NULL' failed (2)

Harmless, ignore.

5. The data contains information about the latest messages to/from the contacts, but the plugin does not appear to use it.

Yes, we drop that intentionally, it would be annoying to repeat the messages on every login.

6. Trying to send a message to a "dead" id, produces the following error: {"msg":"ChannelProtocolError","reason":"Invalid frame: List((/data(0)(0)/groupId,List(ValidationError(error.expected.jsstring,WrappedArray()))))"}

This would be more useful with the preceding frame.

7. Sending a message to a "live" id, results in over a 100 "SyncBatch" / "SyncAck" pairs.

Known issue, likely harmless.

[alexolog]

Harmless, ignore.

Shouldn't be an assert then :)

Yes, we drop that intentionally, it would be annoying to repeat the messages on every login.

I use Pidgin in multiple locations. It is very inconvenient to continue a conversation that was started in another location without having access to the context.

What is "annoying" to some is a n extremely useful feature for others. Having an option to enable/disable it would be best.

This would be more useful with the preceding frame.

Here it is: (The DNS lookup, certificate exchange, etc. happens after every failed message)

(22:34:35) yahoo: sending frame: {"seq":1619,"ack":1613,"data":[[{"msg":"InsertItem","groupId":null,"opId":3,"message":"test","itemId":"000028C0BC99FFFF","expectedMediaCount":0}]]}
(22:34:35) yahoo: frame_len: 146
(22:34:35) yahoo: got frame data: {"msg":"ChannelProtocolError","reason":"Invalid frame: List((/data(0)(0)/groupId,List(ValidationError(error.expected.jsstring,WrappedArray()))))"}
(22:34:35) dnsquery: Performing DNS lookup for prod.iris.yahoo.com
(22:34:35) dnsquery: IP resolved for prod.iris.yahoo.com
(22:34:35) proxy: Attempting connection to 63.250.200.45
(22:34:35) proxy: Connecting to prod.iris.yahoo.com:443 with no proxy
(22:34:35) proxy: Connection in progress
(22:34:35) proxy: Connecting to prod.iris.yahoo.com:443.
(22:34:35) proxy: Connected to prod.iris.yahoo.com:443.
(22:34:35) nss: SSL version 3.3 using 128-bit AES-GCM with 128-bit AEAD MAC
Server Auth: 2048-bit RSA, Key Exchange: 256-bit ECDHE, Compression: NULL
Cipher Suite Name: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
(22:34:35) nss: subject=CN=*.iris.yahoo.com,OU=Information Technology,O=Yahoo Inc.,L=Sunnyvale,ST=California,C=US issuer=CN=Symantec Class 3 Secure Server CA - G4,OU=Symantec Trust Network,O=Symantec Corporation,C=US
(22:34:35) nss: partial certificate chain
(22:34:35) certificate/x509/tls_cached: Starting verify for prod.iris.yahoo.com
(22:34:35) certificate/x509/tls_cached: Checking for cached cert...
(22:34:35) certificate/x509/tls_cached: ...Found cached cert
(22:34:35) nss/x509: Loading certificate from C:\Documents and Settings\me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(22:34:35) certificate/x509/tls_cached: Peer cert matched cached
(22:34:35) nss/x509: Exporting certificate to C:\Documents and Settings\me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(22:34:35) util: Writing file C:\Documents and Settings\me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(22:34:35) nss: Trusting CN=*.iris.yahoo.com,OU=Information Technology,O=Yahoo Inc.,L=Sunnyvale,ST=California,C=US
(22:34:35) certificate: Successfully verified certificate for prod.iris.yahoo.com
(22:34:35) yahoo: frame_len: 54
(22:34:35) yahoo: got frame data: {"seq":1613,"ack":1619,"data":[],"time":1472870083885}
(22:34:37) util: Writing file prefs.xml to directory C:\Documents and Settings\me\Application Data\.purple
(22:34:37) util: Writing file C:\Documents and Settings\me\Application Data\.purple\prefs.xml
(22:34:41) util: Writing file accounts.xml to directory C:\Documents and Settings\me\Application Data\.purple
(22:34:41) util: Writing file C:\Documents and Settings\me\Application Data\.purple\accounts.xml

Known issue, likely harmless.

It's growing. 250 SynchBatch messages after a message, Does the native client do that as well?

[EionRobb]

What dequis means is that the plugin records the last received message timestamp for that instance of pidgin, it should still be syncing messages accross all endpoints

That "groupId":null in the debug log is what's causing the errors and suspequent disconnect and shouldn't be happening. Are those test messages going to people that you haven't had a conversation with yet?

[alexolog]

I am not sure I follow. When I just added the Y2016 account, a lot of my old conversations (which were made on the old Yahoo account) appeared in the log, but were not shown to me when I opened a conversation window with the buddies. If the timestamp is per-conversation, I should have been shown the history. If the timestamp is global, it's the wrong approach.

Incidentally, it seems that Yahoo were serious when they said the new protocol is "conversation-centric". Every time somebody starts a new conversation with you instead of continuing a previous one, it creates a new (group) contact.

The native and web clients hide this but Pidgin creates another buddy that is identified only by a 26-character id.

[alexolog]

The conversations were with people that I talked with before (on the old Yahoo protocol). However, as I mentioned above, Pidgin presented me with two or more buddies for each person I conversed with.

Some of those buddies were "dead", in the sense that I couldn't send messages to them via Pidgin. If I tried to send a message to those IDs via the web interface, it rerouted them to the "live" ids instead.

[EionRobb]

Are there any MutationResponse's in the initial list that associate the dead ids with the not dead ones?

[alexolog]

I can't find the string "mutation" in the log, but I did some digging and found some connection between them. See above: https://github.com/EionRobb/funyahoo-plusplus/issues/19#issuecomment-244494420

I can email you the (slightly sanitized) JSONs of the initial lists if it will help.

[dequis]

I use Pidgin in multiple locations. It is very inconvenient to continue a conversation that was started in another location without having access to the context.

Oh dammit, so there's a legitimate reason to skip messages based on timestamps. Annoying. That method was causing random message loss because yahoo is random, and others were complaining about disk usage spikes.

Just forget about multiple client support for now, we'd prefer to focus on basic functionality. Really not the moment to address every single nitpick when we can barely send and receive messages. Stupid deceptively simple protocol.

[alexolog]

One step at the time.

If you need help with beta testing, I can try.

[dequis]

Can you test again with the latest revision?

[alexolog]

The duplicated and "dead" buddies? Yes, still getting them. I deleted my blist.xml and it got repopulated with the junk.

[dequis]

Is that the only remaining issue out of everything that was mentioned here? Should we just merge this with #2?

EDIT: can you email a new, full, minimally sanitized log? (ideally just removing the password). I'm [email protected], also cc eion at [email protected]. And mention which buddies are duplicated/dead.

[alexolog]

email sent

[alexolog]

Any luck?

[alexolog]

Any progress?