search

EionRobb / funyahoo-plusplus

A replacement Yahoo prpl (protocol plugin) for Pidgin/libpurple
GNU General Public License v3.0
59 stars 11 forks source link

protocol spontaneously exists with "unknown error" after an hour or so #26

Closed alexolog closed 8 years ago

dequis commented 8 years ago

debug log

alexolog commented 8 years ago

Unfortunately didn't happen when I opened the debug window and let it run for 3 hours straight

dequis commented 8 years ago

Well, reopen if you catch it.

alexolog commented 8 years ago

After leaving it running overnight with the debug window open, I caught the error.

Here is the (slightly cooked) debug log:

(03:21:12) yahoo: websocket closed
(03:21:12) dnsquery: Performing DNS lookup for prod.iris.yahoo.com
(03:21:12) dnsquery: IP resolved for prod.iris.yahoo.com
(03:21:12) proxy: Attempting connection to 72.30.2.181
(03:21:12) proxy: Connecting to prod.iris.yahoo.com:443 with no proxy
(03:21:12) proxy: Connection in progress
(03:21:12) proxy: Connecting to prod.iris.yahoo.com:443.
(03:21:12) proxy: Connected to prod.iris.yahoo.com:443.
(03:21:12) 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
(03:21:12) 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
(03:21:12) nss: subject=CN=Symantec Class 3 Secure Server CA - G4,OU=Symantec Trust Network,O=Symantec Corporation,C=US issuer=CN=VeriSign Class 3 Public Primary Certification Authority - G5,OU="(c) 2006 VeriSign, Inc. - For authorized use only",OU=VeriSign Trust Network,O="VeriSign, Inc.",C=US
(03:21:12) nss: subject=CN=VeriSign Class 3 Public Primary Certification Authority - G5,OU="(c) 2006 VeriSign, Inc. - For authorized use only",OU=VeriSign Trust Network,O="VeriSign, Inc.",C=US issuer=OU=Class 3 Public Primary Certification Authority,O="VeriSign, Inc.",C=US
(03:21:12) nss: partial certificate chain
(03:21:12) certificate/x509/tls_cached: Starting verify for prod.iris.yahoo.com
(03:21:12) certificate/x509/tls_cached: Checking for cached cert...
(03:21:12) certificate/x509/tls_cached: ...Found cached cert
(03:21:12) nss/x509: Loading certificate from C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) certificate/x509/tls_cached: Peer cert matched cached
(03:21:12) nss/x509: Exporting certificate to C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) util: Writing file C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) nss: Trusting CN=*.iris.yahoo.com,OU=Information Technology,O=Yahoo Inc.,L=Sunnyvale,ST=California,C=US
(03:21:12) certificate: Successfully verified certificate for prod.iris.yahoo.com
(03:21:12) yahoo: frame_len: 25
(03:21:12) yahoo: got frame data: {"msg":"ChannelNotFound"}
(03:21:12) yahoo: Fetching url https://prod.iris.yahoo.com/prod/rpc?wait=1&v=1
(03:21:12) yahoo: With postdata {"msg":"ReopenSession","sessionToken":"xxxxxxxxxxxxxxxxxxxxxxxxDI.xxxxxxxxxxxxxxxxxxxxxxxx5U.xxxxxxxxxxxxxxee","batch":[],"version":{"platform":"web","app":"iris/dogfood","appVersion":929}}
(03:21:12) util: requesting to fetch a URL
(03:21:12) dnsquery: Performing DNS lookup for prod.iris.yahoo.com
(03:21:12) yahoo: websocket closed
(03:21:12) dnsquery: Performing DNS lookup for prod.iris.yahoo.com
(03:21:12) dnsquery: IP resolved for prod.iris.yahoo.com
(03:21:12) proxy: Attempting connection to 72.30.2.181
(03:21:12) proxy: Connecting to prod.iris.yahoo.com:443 with no proxy
(03:21:12) proxy: Connection in progress
(03:21:12) dnsquery: IP resolved for prod.iris.yahoo.com
(03:21:12) proxy: Attempting connection to 72.30.2.181
(03:21:12) proxy: Connecting to prod.iris.yahoo.com:443 with no proxy
(03:21:12) proxy: Connection in progress
(03:21:12) proxy: Connecting to prod.iris.yahoo.com:443.
(03:21:12) proxy: Connected to prod.iris.yahoo.com:443.
(03:21:12) proxy: Connecting to prod.iris.yahoo.com:443.
(03:21:12) proxy: Connected to prod.iris.yahoo.com:443.
(03:21:12) 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
(03:21:12) 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
(03:21:12) nss: partial certificate chain
(03:21:12) certificate/x509/tls_cached: Starting verify for prod.iris.yahoo.com
(03:21:12) certificate/x509/tls_cached: Checking for cached cert...
(03:21:12) certificate/x509/tls_cached: ...Found cached cert
(03:21:12) nss/x509: Loading certificate from C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) certificate/x509/tls_cached: Peer cert matched cached
(03:21:12) nss/x509: Exporting certificate to C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) util: Writing file C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) nss: Trusting CN=*.iris.yahoo.com,OU=Information Technology,O=Yahoo Inc.,L=Sunnyvale,ST=California,C=US
(03:21:12) certificate: Successfully verified certificate for prod.iris.yahoo.com
(03:21:12) 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
(03:21:12) 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
(03:21:12) nss: partial certificate chain
(03:21:12) certificate/x509/tls_cached: Starting verify for prod.iris.yahoo.com
(03:21:12) certificate/x509/tls_cached: Checking for cached cert...
(03:21:12) certificate/x509/tls_cached: ...Found cached cert
(03:21:12) nss/x509: Loading certificate from C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) certificate/x509/tls_cached: Peer cert matched cached
(03:21:12) nss/x509: Exporting certificate to C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) util: Writing file C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) nss: Trusting CN=*.iris.yahoo.com,OU=Information Technology,O=Yahoo Inc.,L=Sunnyvale,ST=California,C=US
(03:21:12) certificate: Successfully verified certificate for prod.iris.yahoo.com
(03:21:12) util: request constructed
(03:21:12) yahoo: frame_len: 25
(03:21:12) yahoo: got frame data: {"msg":"ChannelNotFound"}
(03:21:12) yahoo: Fetching url https://prod.iris.yahoo.com/prod/rpc?wait=1&v=1
(03:21:12) yahoo: With postdata {"msg":"ReopenSession","sessionToken":"xxxxxxxxxxxxxxxxxxxxxxxxDI.xxxxxxxxxxxxxxxxxxxxxxxx5U.xxxxxxxxxxxxxxee","batch":[],"version":{"platform":"web","app":"iris/dogfood","appVersion":929}}
(03:21:12) util: requesting to fetch a URL
(03:21:12) dnsquery: Performing DNS lookup for prod.iris.yahoo.com
(03:21:12) yahoo: websocket closed
(03:21:12) dnsquery: Performing DNS lookup for prod.iris.yahoo.com
(03:21:12) dnsquery: IP resolved for prod.iris.yahoo.com
(03:21:12) proxy: Attempting connection to 72.30.2.181
(03:21:12) proxy: Connecting to prod.iris.yahoo.com:443 with no proxy
(03:21:12) proxy: Connection in progress
(03:21:12) dnsquery: IP resolved for prod.iris.yahoo.com
(03:21:12) proxy: Attempting connection to 72.30.2.181
(03:21:12) proxy: Connecting to prod.iris.yahoo.com:443 with no proxy
(03:21:12) proxy: Connection in progress
(03:21:12) proxy: Connecting to prod.iris.yahoo.com:443.
(03:21:12) proxy: Connected to prod.iris.yahoo.com:443.
(03:21:12) proxy: Connecting to prod.iris.yahoo.com:443.
(03:21:12) proxy: Connected to prod.iris.yahoo.com:443.
(03:21:12) 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
(03:21:12) 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
(03:21:12) nss: partial certificate chain
(03:21:12) certificate/x509/tls_cached: Starting verify for prod.iris.yahoo.com
(03:21:12) certificate/x509/tls_cached: Checking for cached cert...
(03:21:12) certificate/x509/tls_cached: ...Found cached cert
(03:21:12) nss/x509: Loading certificate from C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) certificate/x509/tls_cached: Peer cert matched cached
(03:21:12) nss/x509: Exporting certificate to C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) util: Writing file C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) nss: Trusting CN=*.iris.yahoo.com,OU=Information Technology,O=Yahoo Inc.,L=Sunnyvale,ST=California,C=US
(03:21:12) certificate: Successfully verified certificate for prod.iris.yahoo.com
(03:21:12) util: request constructed
(03:21:12) 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
(03:21:12) 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
(03:21:12) nss: partial certificate chain
(03:21:12) certificate/x509/tls_cached: Starting verify for prod.iris.yahoo.com
(03:21:12) certificate/x509/tls_cached: Checking for cached cert...
(03:21:12) certificate/x509/tls_cached: ...Found cached cert
(03:21:12) nss/x509: Loading certificate from C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) certificate/x509/tls_cached: Peer cert matched cached
(03:21:12) nss/x509: Exporting certificate to C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) util: Writing file C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) nss: Trusting CN=*.iris.yahoo.com,OU=Information Technology,O=Yahoo Inc.,L=Sunnyvale,ST=California,C=US
(03:21:12) certificate: Successfully verified certificate for prod.iris.yahoo.com
(03:21:12) util: Response headers: 'HTTP/1.1 200 OK

Date: Sat, 10 Sep 2016 07:21:24 GMT

Content-Type: application/json; charset=utf-8

Content-Length: 331

Connection: close

Vary: Accept-Encoding

Server: nginx-clojure

Cache-Control: private, no-cache, no-store, must-revalidate

Access-Control-Allow-Origin: null

Access-Control-Allow-Headers: Content-Type

Access-Control-Allow-Headers: Accept

Access-Control-Allow-Headers: Content-Disposition

Access-Control-Allow-Credentials: false

Access-Control-Allow-Methods: GET, POST, OPTIONS

'
(03:21:12) util: parsed 331
(03:21:12) yahoo: Got response: 

{"msg":"SessionOpened","userId":"xxxxxxxxxxxxxxxxxxxxxxxxDI","deviceId":"xxxxxxxxxxxxxx9a","accessToken":"xxxxxxxxxxxxxxxxxxxxxxxxDI.xxxxxxxxxxxxxxxxxxxxxxxx5U","sessionToken":"xxxxxxxxxxxxxxxxxxxxxxxxDI.xxxxxxxxxxxxxxxxxxxxxxxx5U.xxxxxxxxxxxxxxee","channelId":"38f2f1d9","sessionType":"mobile","idleTimeoutMs":14400000,"batch":[]}
(03:21:12) pbar: nickname changed to "MyNick" by signed-on account
(03:21:12) account: Invalid status ID 'tune' for account my_account (prpl-eionrobb-funyahoo-plusplus)
(03:21:12) account: Invalid status ID 'mood' for account my_account (prpl-eionrobb-funyahoo-plusplus)
(03:21:12) pbar: aliases not supported by "prpl-eionrobb-funyahoo-plusplus"

/--------- BEGIN REPEATING SECTION 1 (repeated 346 times) ---------\

(03:21:12) dnsquery: Performing DNS lookup for prod.iris.yahoo.com
(03:21:12) dnsquery: IP resolved for prod.iris.yahoo.com
(03:21:12) proxy: Attempting connection to 72.30.2.181
(03:21:12) proxy: Connecting to prod.iris.yahoo.com:443 with no proxy
(03:21:12) proxy: Connection in progress
(03:21:12) proxy: Connecting to prod.iris.yahoo.com:443.
(03:21:12) proxy: Connected to prod.iris.yahoo.com:443.
(03:21:12) 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
(03:21:12) 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
(03:21:12) nss: partial certificate chain
(03:21:12) certificate/x509/tls_cached: Starting verify for prod.iris.yahoo.com
(03:21:12) certificate/x509/tls_cached: Checking for cached cert...
(03:21:12) certificate/x509/tls_cached: ...Found cached cert
(03:21:12) nss/x509: Loading certificate from C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) certificate/x509/tls_cached: Peer cert matched cached
(03:21:12) nss/x509: Exporting certificate to C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) util: Writing file C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:21:12) nss: Trusting CN=*.iris.yahoo.com,OU=Information Technology,O=Yahoo Inc.,L=Sunnyvale,ST=California,C=US
(03:21:12) certificate: Successfully verified certificate for prod.iris.yahoo.com
(03:21:12) yahoo: frame_len: 77
(03:21:12) yahoo: got frame data: {"msg":"ChannelProtocolError","reason":"Client ack 151 exceeds server seq 1"}

\--------- END REPEATING SECTION 1 (repeated 345 times) ---------/

/--------- BEGIN REPEATING SECTION 2 (repeated 240 times) ---------\

(03:22:23) dnsquery: Performing DNS lookup for prod.iris.yahoo.com
(03:22:23) dnsquery: IP resolved for prod.iris.yahoo.com
(03:22:23) proxy: Attempting connection to 63.250.200.45
(03:22:23) proxy: Connecting to prod.iris.yahoo.com:443 with no proxy
(03:22:23) proxy: Connection in progress
(03:22:23) proxy: Connecting to prod.iris.yahoo.com:443.
(03:22:23) proxy: Connected to prod.iris.yahoo.com:443.
(03:22:24) 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
(03:22:24) 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
(03:22:24) nss: subject=CN=Symantec Class 3 Secure Server CA - G4,OU=Symantec Trust Network,O=Symantec Corporation,C=US issuer=CN=VeriSign Class 3 Public Primary Certification Authority - G5,OU="(c) 2006 VeriSign, Inc. - For authorized use only",OU=VeriSign Trust Network,O="VeriSign, Inc.",C=US
(03:22:24) nss: subject=CN=VeriSign Class 3 Public Primary Certification Authority - G5,OU="(c) 2006 VeriSign, Inc. - For authorized use only",OU=VeriSign Trust Network,O="VeriSign, Inc.",C=US issuer=OU=Class 3 Public Primary Certification Authority,O="VeriSign, Inc.",C=US
(03:22:24) nss: partial certificate chain
(03:22:24) certificate/x509/tls_cached: Starting verify for prod.iris.yahoo.com
(03:22:24) certificate/x509/tls_cached: Checking for cached cert...
(03:22:24) certificate/x509/tls_cached: ...Found cached cert
(03:22:24) nss/x509: Loading certificate from C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:22:24) certificate/x509/tls_cached: Peer cert matched cached
(03:22:24) nss/x509: Exporting certificate to C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:22:24) util: Writing file C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(03:22:24) nss: Trusting CN=*.iris.yahoo.com,OU=Information Technology,O=Yahoo Inc.,L=Sunnyvale,ST=California,C=US
(03:22:24) certificate: Successfully verified certificate for prod.iris.yahoo.com
(03:22:24) yahoo: frame_len: 77

\--------- END REPEATING SECTION 2 (repeated 240 times) ---------/

(03:23:12) dnsquery: Performing DNS lookup for prod.iris.yahoo.com
(03:23:12) dnsquery: IP resolved for prod.iris.yahoo.com
(03:23:12) proxy: Attempting connection to 63.250.200.45
(03:23:12) proxy: Connecting to prod.iris.yahoo.com:443 with no proxy
(03:23:12) proxy: Connection in progress
(03:23:12) util: Response headers: 'HTTP/1.1 500 Internal Server Error

Date: Sat, 10 Sep 2016 07:23:24 GMT

Connection: close

Server: nginx-clojure

Access-Control-Allow-Origin: null

Access-Control-Allow-Headers: Content-Type

Access-Control-Allow-Headers: Accept

Access-Control-Allow-Headers: Content-Disposition

Access-Control-Allow-Credentials: false

Access-Control-Allow-Methods: GET, POST, OPTIONS

'
(03:23:12) yahoo: Got response: 

(03:23:12) connection: purple_connection_error_reason called with NULL description
(03:23:12) connection: Connection error on 034699E0 (reason: 16 description: Unknown error)
(03:23:12) account: Disconnecting account my_account (01228B08)
(03:23:12) connection: Disconnecting connection 034699E0
(03:23:12) idle: Setting thelurker_y unidle
(03:23:12) connection: Destroying connection 034699E0
(03:23:18) util: Writing file accounts.xml to directory C:\Documents and Settings\Me\Application Data\.purple
(03:23:18) util: Writing file C:\Documents and Settings\Me\Application Data\.purple\accounts.xml
(03:23:18) util: Writing file blist.xml to directory C:\Documents and Settings\Me\Application Data\.purple
(03:23:18) util: Writing file C:\Documents and Settings\Me\Application Data\.purple\blist.xml
alexolog commented 8 years ago

Since I am not a collaborator, I cannot reopen the issue

dequis commented 8 years ago

/--------- BEGIN REPEATING SECTION 1 (repeated 346 times) ---------\

[1 minute 11 seconds later]

/--------- END REPEATING SECTION 1 (repeated 346 times) ---------\

That's 4.85 repeats per second!

And then uh... it stops replying? Then gives up completely?

@EionRobb this is so sad it's funny

alexolog commented 8 years ago

I noticed another recurrence just now, but without the disconnection. repeating continuously until I disconnect and reconnect the protocol:

(11:38:40) dnsquery: Performing DNS lookup for prod.iris.yahoo.com
(11:38:40) dnsquery: IP resolved for prod.iris.yahoo.com
(11:38:40) proxy: Attempting connection to 72.30.2.181
(11:38:40) proxy: Connecting to prod.iris.yahoo.com:443 with no proxy
(11:38:40) proxy: Connection in progress
(11:38:40) proxy: Connecting to prod.iris.yahoo.com:443.
(11:38:40) proxy: Connected to prod.iris.yahoo.com:443.
(11:38:40) 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
(11:38:40) 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
(11:38:40) nss: partial certificate chain
(11:38:40) certificate/x509/tls_cached: Starting verify for prod.iris.yahoo.com
(11:38:40) certificate/x509/tls_cached: Checking for cached cert...
(11:38:40) certificate/x509/tls_cached: ...Found cached cert
(11:38:40) nss/x509: Loading certificate from C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(11:38:40) certificate/x509/tls_cached: Peer cert matched cached
(11:38:40) nss/x509: Exporting certificate to C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(11:38:40) util: Writing file C:\Documents and Settings\Me\Application Data\.purple\certificates\x509\tls_peers\prod.iris.yahoo.com
(11:38:40) nss: Trusting CN=*.iris.yahoo.com,OU=Information Technology,O=Yahoo Inc.,L=Sunnyvale,ST=California,C=US
(11:38:40) certificate: Successfully verified certificate for prod.iris.yahoo.com
(11:38:40) yahoo: frame_len: 76
(11:38:40) yahoo: got frame data: {"msg":"ChannelProtocolError","reason":"Client ack 19 exceeds server seq 3"}
dequis commented 8 years ago

What we still don't know is what causes those. Client ack 19 exceeds server seq 3 presumably means we restarted the connection because something broke, and were also supposed to reset the ack value instead of keeping it the same way.

We have to figure out what that something is. There must be something before all these repeated chunks that triggers the first disconnection - hopefully some action you do in pidgin, or some event the other contact does.

The ChannelNotFound stuff looks like a good indicator that we have to reset the ack, or probably SessionOpened. But how did we get to ChannelNotFound?

alexolog commented 8 years ago

The previous log that I posted had everything, including the trigger (which I assume was either the 'yahoo: websocket closedor theyahoo: got frame data: {"msg":"ChannelNotFound"}`)

The previous log entry was an hour or so earlier.

dequis commented 8 years ago

Oh okay, so, probably something along the lines of the server closing the channel due to inactivity.

dequis commented 8 years ago

b7477bdd72564bc06bcf91026c87f6c308ab32c5 handles the ChannelNotFound issue (still don't really know how to trigger it, but I made it send invalid channel ids randomly to reproduce it)

e9aff878889c70841d6a30bfa89e1c29afac15c4 handles the infinite reconnection loop, which is what probably leads to a server error - but if it's not that, then it's probably just a legitimate server issue.

Here's a build I made for you http://dequis.org/libyahoo-plusplus.dll, should show up with version string 0.9.2016.09.10.git.r56.e9aff87 in the plugin information window. Eion will probably update the more-official url later.

alexolog commented 8 years ago

Please reopen, problem still happens (albeit less frequently)

Log (sanitized): https://paste.ee/p/VtVUo

Probable cause: yahoo: got frame data: {"msg":"ChannelNotFound"}

Possible suggestion: When getting "msg":"SessionOpened", check the "idleTimeoutMs":nnn element and set a recurring timer to initiate some activity after 50-90% of the expiration time.

dequis commented 8 years ago

I don't see any issues left that are our fault there - that's just the server breaking sometimes. It doesn't even show a proper error response, hard-failing the connection is the correct thing to do in these cases.

alexolog commented 8 years ago

I am not trying to assign "fault", but finding a way to work around it will be appreciated.

dequis commented 8 years ago

Does it not attempt to reconnect?

alexolog commented 8 years ago

No, it doesn't.

An automatic reconnect can be a problem if Pidgin is running on several computers concurrently and the protocol only allows one connection -- each instance will try to reconnect, kicking the other out. I don't know whether that's the case with Yahoo or not.