Twitter connector gets stuck not running any synclets, delaying them all

[mdz]

Log looks like this:

14 Mar 21:28:22 - verbose: delaying related
14 Mar 21:28:22 - verbose: delaying self
14 Mar 21:28:32 - verbose: delaying mentions
14 Mar 21:28:32 - verbose: delaying tweets
14 Mar 21:28:32 - verbose: delaying mentions
14 Mar 21:28:32 - verbose: delaying friends
14 Mar 21:28:32 - verbose: delaying self
14 Mar 21:28:32 - verbose: delaying related
14 Mar 21:28:32 - verbose: delaying related
14 Mar 21:28:32 - verbose: delaying self
14 Mar 21:28:42 - verbose: delaying mentions
14 Mar 21:28:42 - verbose: delaying tweets
14 Mar 21:28:42 - verbose: delaying mentions
14 Mar 21:28:42 - verbose: delaying friends
14 Mar 21:28:42 - verbose: delaying self
14 Mar 21:28:42 - verbose: delaying related
14 Mar 21:28:42 - verbose: delaying related
14 Mar 21:28:42 - verbose: delaying self
14 Mar 21:28:52 - verbose: delaying mentions
14 Mar 21:28:52 - verbose: delaying tweets
14 Mar 21:28:52 - verbose: delaying mentions
14 Mar 21:28:52 - verbose: delaying friends
14 Mar 21:28:52 - verbose: delaying self
14 Mar 21:28:52 - verbose: delaying related
14 Mar 21:28:52 - verbose: delaying related
14 Mar 21:28:52 - verbose: delaying self
14 Mar 21:29:02 - verbose: delaying mentions
14 Mar 21:29:02 - verbose: delaying tweets
14 Mar 21:29:02 - verbose: delaying mentions
14 Mar 21:29:02 - verbose: delaying friends
14 Mar 21:29:02 - verbose: delaying self
14 Mar 21:29:02 - verbose: delaying related
14 Mar 21:29:02 - verbose: delaying related
14 Mar 21:29:02 - verbose: delaying self
14 Mar 21:29:12 - verbose: delaying mentions
14 Mar 21:29:12 - verbose: delaying tweets
14 Mar 21:29:12 - verbose: delaying mentions
14 Mar 21:29:12 - verbose: delaying friends
14 Mar 21:29:12 - verbose: delaying self
14 Mar 21:29:12 - verbose: delaying related
14 Mar 21:29:12 - verbose: delaying related
14 Mar 21:29:12 - verbose: delaying self
14 Mar 21:29:22 - verbose: delaying mentions
14 Mar 21:29:22 - verbose: delaying tweets
14 Mar 21:29:22 - verbose: delaying mentions
14 Mar 21:29:22 - verbose: delaying friends
14 Mar 21:29:22 - verbose: delaying self
14 Mar 21:29:22 - verbose: delaying related
14 Mar 21:29:22 - verbose: delaying related

with no twitter synclets running for many hours

[smurthas]

Was a synclet actually running/stuck at the time, or was this just tolerance?

[othiym23]

@temas investigated this, and it seemed like the timeline synclet had hung without crashing in a way that the sync manager could recover, causing all the other synclets to be delayed.

[mdz]

Something was definitely stuck. No twitter synclets had run since:

14 Mar 06:51:27 - info: Synclet friends finished for twitter timing 40421
14 Mar 06:51:27 - verbose: scheduling twitter-friends (freq 3600) to run in 3818.298s
[...]
14 Mar 06:51:48 - verbose: Sending 1456 batched events to http://localhost:8042/Me/search/events
14 Mar 06:51:48 - verbose: proxying POST /Me/search/events to http://localhost:44477//events
[...]
14 Mar 06:51:49 - verbose: Done sending batched events to http://localhost:8042/Me/search/events
[...]
14 Mar 06:55:19 - info: Synclet timeline starting for twitter

Looks like timeline is probably the one that got stuck.

[mdz]

This seems to be happening with the twitter connector across a great many (but not all) of our accounts.

[temas]

So it's definitely only twitter right now, and it's not isolated to timeline, I've seen tweets do it too. Netstat has no open sockets and lsof has no interesting open files. I'm going to do another code review on the twitter paging code now. My gut is telling me it's escaping from there somehow.

[smurthas]

Still see this (only for contacts):

17 Mar 00:27:07 - verbose: delaying contacts
17 Mar 00:27:17 - verbose: delaying contacts
17 Mar 00:27:17 - verbose: delaying contacts
17 Mar 00:27:27 - verbose: delaying contacts
17 Mar 00:27:27 - verbose: delaying contacts
17 Mar 00:27:37 - verbose: delaying contacts
17 Mar 00:27:37 - verbose: delaying contacts
17 Mar 00:27:47 - verbose: delaying contacts
17 Mar 00:27:47 - verbose: delaying contacts
17 Mar 00:27:57 - verbose: delaying contacts
17 Mar 00:27:57 - verbose: delaying contacts
17 Mar 00:28:07 - verbose: delaying contacts
17 Mar 00:28:07 - verbose: delaying contacts
17 Mar 00:28:17 - verbose: delaying contacts
17 Mar 00:28:17 - verbose: delaying contacts
17 Mar 00:28:27 - verbose: delaying contacts
17 Mar 00:28:27 - verbose: delaying contacts
17 Mar 00:28:37 - verbose: delaying contacts
17 Mar 00:28:37 - verbose: delaying contacts
17 Mar 00:28:47 - verbose: delaying contacts
17 Mar 00:28:47 - verbose: delaying contacts
17 Mar 00:28:57 - verbose: delaying contacts
17 Mar 00:28:57 - verbose: delaying contacts
17 Mar 00:29:07 - verbose: delaying contacts
17 Mar 00:29:07 - verbose: delaying contacts
17 Mar 00:29:17 - verbose: delaying contacts

Not all accounts. My super fast and unscientific internal pattern matching pinned it to old accounts (there were about 5, 3 of which were singleton's accounts), all were on 1, 6, and 7.

Can't tell which connector. We need to improve the logging there.

[smurthas]

of note, this isn't twitter, as twitter has friends, not contacts. Adding logging right now and will update with the results.

[smurthas]

This is gcontacts.

17 Mar 02:54:36 - verbose: delaying gcontacts/contacts
17 Mar 02:54:36 - verbose: delaying gcontacts/contacts
17 Mar 02:54:46 - verbose: delaying gcontacts/contacts
17 Mar 02:54:46 - verbose: delaying gcontacts/contacts
17 Mar 02:54:56 - verbose: delaying gcontacts/contacts
17 Mar 02:54:56 - verbose: delaying gcontacts/contacts
17 Mar 02:55:06 - verbose: delaying gcontacts/contacts

Interestingly, it seems to have more than one copy running. This seems likely to be a scheduling bug coupled with a gcontacts bug (if there was a twitter bug, it has been squashed).

[mdz]

I've filed the gcontacts issue as #933. Closing this one as it's resolved.