search

ViennaRSS / vienna-rss

Vienna is a free and open-source RSS/Atom newsreader for macOS.
https://www.vienna-rss.com
Apache License 2.0
1.85k stars 227 forks source link

unable to add http://feeds.feedburner.com/99pi from InoReader #635

Closed bwelling closed 8 years ago

bwelling commented 8 years ago

If I attempt to add this feed to Inoreader, it doesn't show up in Vienna, any future refresh of Vienna hangs, and the following is logged to the console. It's completely reproducible for me. This happens both when adding the feed on Inoreader directly and through Vienna.

5/4/16 10:45:27.904 AM Vienna[41022]: *\ -[__NSPlaceholderArray initWithObjects:count:]: attempt to insert nil object from objects[2]

5/4/16 10:45:27.905 AM Vienna[41022]: ( 0 CoreFoundation 0x00007fff9d86f4f2 exceptionPreprocess + 178 1 libobjc.A.dylib 0x00007fff8d62a73c objc_exception_throw + 48 2 CoreFoundation 0x00007fff9d761372 -[NSPlaceholderArray initWithObjects:count:] + 290 3 CoreFoundation 0x00007fff9d76a0d4 +[NSArray arrayWithObjects:count:] + 52 4 Vienna 0x0000000100c81a8f Vienna + 203407 5 Vienna 0x0000000100cea061 Vienna + 630881 6 Foundation 0x00007fff92358f5e NSThreadPerformPerform + 279 7 CoreFoundation 0x00007fff9d804881 __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION + 17 8 CoreFoundation 0x00007fff9d7e3fbc CFRunLoopDoSources0 + 556 9 CoreFoundation 0x00007fff9d7e34df CFRunLoopRun + 927 10 CoreFoundation 0x00007fff9d7e2ed8 CFRunLoopRunSpecific + 296 11 HIToolbox 0x00007fff9896c935 RunCurrentEventLoopInMode + 235 12 HIToolbox 0x00007fff9896c76f ReceiveNextEventCommon + 432 13 HIToolbox 0x00007fff9896c5af _BlockUntilNextEventMatchingListInModeWithFilter + 71 14 AppKit 0x00007fff9e0c1efa _DPSNextEvent + 1067 15 AppKit 0x00007fff9e0c132a -[NSApplication _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 454 16 AppKit 0x00007fff9e0b5e84 -[NSApplication run] + 682 17 AppKit 0x00007fff9e07f46c NSApplicationMain + 1176 18 libdyld.dylib 0x00007fff922d85ad start + 1 )

barijaona commented 8 years ago

I could not reproduce the problem. @bwelling, could you please provide the complete crashlog ?

bwelling commented 8 years ago

The process didn't crash; it hung. There are some .hang files, but they appear to be the entire state of the machine, not the Vienna process (and they're in some binary format that I can't attach here).

barijaona commented 8 years ago

You can zip them and attach them here

bwelling commented 8 years ago

Vienna_2016-05-04-104954_wavelet.hang.gz

barijaona commented 8 years ago

It appears that the slowdown is caused by the logging in process, which unfortunately is still running synchronously on the main thread (I plan to change this later, probably in 3.2).

I suggest that, before trying to add this particular feed, you make sure Vienna is successfully logged in to Inoreader. For instance, you could use the « File -> Update Subscriptions from Open Reader » menu command, or refresh another feed. If the problem still occurs on adding « 99% Invisible » , please upload again the .hang here.

bwelling commented 8 years ago

This happened multiple times, and Vienna was connected to InoReader in all of them. In each case, the refresh successfully updated all of the other feeds, but the new feed didn't show up, and the refresh button never switched back from the X to the normal icon.

bwelling commented 8 years ago

Also, in between the failures, I restarted Vienna, and logged out and back in to InoReader.

barijaona commented 8 years ago

As I said, I could not reproduce the problem with my own Inoreader account, and the .hang file you uploaded does not show interesting data.

To investigate, I need a .hand done under the conditions I described an hour ago.

bwelling commented 8 years ago

I think I see why the .hang file isn't useful.

What's happening is that if I add the feed, the sync from InoReader hangs (as evidenced by the refresh button icon being an X), and the new feed doesn't show up. If I then quit and restart Vienna, it hangs on startup (beachball spinning), and if I then Force Quit, I get the .hang file. I'm including a new one, but I'm guessing it will be the same as before.

Is there something I could do to enable verbose logging or debugging during the initial attempt?

Vienna_2016-05-08-175106_wavelet.hang.gz

barijaona commented 8 years ago

You're right, the .hang is similar to the previous one.

But I am surprised by the suspected link between the hang and this particular feed. If you suppress the feed from the web interface of Inoreader, then relaunch Vienna, does the hang still happen ? (please be patient to be sure).

If Vienna hangs at startup, you can temporarily disable refreshes at startup by typing in Terminal : 

defaults write uk.co.opencommunity.vienna2 CheckForNewMessagesOnStartup false

Relaunch Vienna, make sure Vienna is logged into Inoreader as suggested above, and try adding again the feed.

bwelling commented 8 years ago

I'm not sure what you mean by suppressing the feed. If I remove the feed from InoReader, Vienna will sometimes start, and sometimes get into a state where it can't authenticate to InoReader. In the latter case, if I open Vienna's preferences, the InoReader password field has been cleared, and re-entering my password fixes the problem.

If I change the default and start Vienna, and then attempt to add the feed, it has the same behavior as before; it causes a connection to add the new feed, and this refresh hangs. Vienna is still usable, but the refresh isn't completing, and the new feed isn't showing up.

barijaona commented 8 years ago

Sorry, but something is not completely clear for me. Is the hang caused by :

Step by step tests would make things clearer. Please, updload hangs with description of their circumstances.

bwelling commented 8 years ago

On May 9, 2016, at 9:48 PM, Barijaona Ramaholimihaso notifications@github.com wrote:

Sorry, but something is not completely clear for me. Is the hang caused by :

logging Vienna in, and getting list of feeds ( « File -> Update Subscriptions from Open Reader » menu command) This causes Vienna to get into a state where the UI works, but refresh is disabled, and nothing updates. refreshing this particular feed (you can refresh it individually through the contextual menu), I can't do this, as the new feed never shows up at all. adding it through Vienna (try adding it through Vienna instead of through Inoreader’s web interface), This is the same as above. or when refreshing all feeds together ?

Same as above.

Step by step tests would make things clearer. Please, updload hangs with description of their circumstances.

There are no hang files created in any of these cases, as the process isn't hung; the refresh never completes.

I'm not sure what other information to provide; I've described everything that I've done.

Vienna is in a working, connected state. If I add this feed, either using the InoReader web interface or through Vienna, it fails to add, and something in Vienna gets wedged (see the log from my original message, and the Refresh icon never comes back).

If, after some amount of time, I quit Vienna and restart, the process completely hangs. If I force quit, I get a hang file like the ones attached.

barijaona commented 8 years ago

Could you try the attached development build (based on current head) ? It should be more verbose in the console log.

Just try the « File -> Update Subscriptions from Open Reader » menu command

Vienna.app.zip

bwelling commented 8 years ago

With the new build, the new feed shows up (for the first time!) but with a warning icon (text: An error occurred when this feed was last refreshed).

Here are the logs, starting when I added the feed.

5/10/16 9:42:22.808 AM Vienna[36667]: GoogleReader.m:250 -[GoogleReader getToken] Start Token Request! 5/10/16 9:42:23.819 AM Vienna[36667]: GoogleReader.m:856 -[GoogleReader subscribeToFeed:] Subscribe response status code: 200 5/10/16 9:42:23.819 AM Vienna[36667]: GoogleReader.m:834 -[GoogleReader loadSubscriptions:] Firing directly 5/10/16 9:42:23.819 AM Vienna[36667]: GoogleReader.m:837 -[GoogleReader loadSubscriptions:] Token available, finish subscription 5/10/16 9:42:24.247 AM Vienna[36667]: GoogleReader.m:739 -[GoogleReader subscriptionsRequestDone:] Ending subscriptionRequest 5/10/16 9:42:24.248 AM Vienna[36667]: GoogleReader.m:935 -[GoogleReader createNewSubscription:] createNewSubscription - START 5/10/16 9:42:24.248 AM Vienna[36667]: Adding Open Reader Feed: http://feeds.feedburner.com/99pi with Title: 99% Invisible 5/10/16 9:42:24.251 AM Vienna[36667]: GoogleReader.m:953 -[GoogleReader createNewSubscription:] createNewSubscription - END 5/10/16 9:42:25.852 AM Vienna[36667]: GoogleReader.m:429 32-[GoogleReader feedRequestDone:]_block_invoke Refresh Done: http://feeds.feedburner.com/99pi 5/10/16 9:42:25.866 AM Vienna[36667]: GoogleReader.m:462 32-[GoogleReader feedRequestDone:]_block_invoke 42 items returned from https://www.inoreader.com/reader/api/0/stream/contents/feed/http%3A%2F%2Ffeeds.feedburner.com%2F99pi?client=ViennaRSS&comments=false&likes=false&ot=0&n=500&ck=1462898544&output=json 5/10/16 9:42:26.083 AM Vienna[36667]: GoogleReader.m:629 32-[GoogleReader readRequestDone:]_block_invoke 2 unread items for https://www.inoreader.com/reader/api/0/stream/items/ids?ck=1462898544&client=ViennaRSS&s=feed/http%3A%2F%2Ffeeds.feedburner.com%2F99pi&xt=user/-/state/com.google/read&n=1000&output=json 5/10/16 9:42:26.301 AM Vienna[36667]: GoogleReader.m:702 35-[GoogleReader starredRequestDone:]_block_invoke 0 starred items for https://www.inoreader.com/reader/api/0/stream/items/ids?ck=1462898544&client=ViennaRSS&s=feed/http%3A%2F%2Ffeeds.feedburner.com%2F99pi&it=user/-/state/com.google/starred&n=1000&output=json 5/10/16 9:42:26.303 AM Vienna[36667]: RefreshManager.m:105 -[RefreshManager nqQueueDidFinishSelector:] Queue empty!!! 5/10/16 9:42:27.172 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.207 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.223 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.239 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.256 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.273 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.340 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.373 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.407 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.441 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.457 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.541 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.625 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.658 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.674 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.708 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.725 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.859 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.875 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.909 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:27.926 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.210 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.243 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.293 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.310 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.376 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.444 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.510 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.561 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.594 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.611 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.627 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.645 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.745 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.761 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.878 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.894 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.912 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.929 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.962 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:28.996 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:29.011 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:29.063 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:29.130 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:29.764 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:29.782 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:29.814 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:29.847 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:30.032 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:30.133 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:30.166 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:30.216 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:30.233 AM Vienna[36667]: Uncommited CATransaction. Set CA_DEBUG_TRANSACTIONS=1 in environment to debug. 5/10/16 9:42:31.866 AM Vienna[36667]: CoreAnimation: warning, deleted thread with uncommitted CATransaction; set CA_DEBUG_TRANSACTIONS=1 in environment to log backtraces. 5/10/16 9:42:33.112 AM Vienna[36667]: RefreshManager.m:105 -[RefreshManager nqQueueDidFinishSelector:] Queue empty!!! 5/10/16 9:42:38.376 AM Vienna[36667]: RefreshManager.m:105 -[RefreshManager nqQueueDidFinishSelector:] Queue empty!!! 5/10/16 9:42:40.619 AM Vienna[36667]: RefreshManager.m:105 -[RefreshManager nqQueueDidFinishSelector:] Queue empty!!! 5/10/16 9:42:44.112 AM Vienna[36667]: CoreAnimation: warning, deleted thread with uncommitted CATransaction; set CA_DEBUG_TRANSACTIONS=1 in environment to log backtraces.

bwelling commented 8 years ago

After that finished, I attempted a full refresh; that also worked, and the warning icon went away.

barijaona commented 8 years ago

Mysterious 😆

bwelling commented 8 years ago

There do seem to be some issues with this build, though; when moving between folders (especially using the ‘skip folder’ button, the list of articles isn’t properly refreshed.

barijaona commented 8 years ago

If this persists, please open a new issue, and provide us with a log and a screenshot of your preferences.

I suggest you do a reindex database first ("Vienna" menu)