search

trakt / Plex-Trakt-Scrobbler

Add what you are watching on Plex to trakt.tv
1.45k stars 166 forks source link

Server Request Timeout with Trakt #107

Closed eknee closed 10 years ago

eknee commented 10 years ago

Keep getting timeout issues when trakt is trying to connect to my server. I modified the media_server.py file so that it uses my internal IP address to access my server since the host name doesn't work for some reason. I still see a timeout though every time it try's to connect.

Using the following metadata from Plex: Movies: The Movie Database, MoviePosterDB, Freebase TV Show: TVDB

From my log:

2014-02-12 20:32:40,216 (-48e0a940) :  INFO (core:336) - Starting framework core - Version: 2.3.16, Build: 2167b3f (Mon Jan 27 21:33:51 UTC 2014)
2014-02-12 20:32:40,216 (-48e0a940) :  DEBUG (core:348) - Using the elevated policy
2014-02-12 20:32:40,216 (-48e0a940) :  DEBUG (core:437) - Starting runtime component.
2014-02-12 20:32:40,218 (-48e0a940) :  DEBUG (core:437) - Starting caching component.
2014-02-12 20:32:40,219 (-48e0a940) :  DEBUG (core:437) - Starting data component.
2014-02-12 20:32:40,219 (-48e0a940) :  DEBUG (core:437) - Starting networking component.
2014-02-12 20:32:40,219 (-48e0a940) :  DEBUG (networking:318) - Loaded HTTP cookies
2014-02-12 20:32:40,220 (-48e0a940) :  DEBUG (networking:504) - Setting the default network timeout to 20.0
2014-02-12 20:32:40,220 (-48e0a940) :  DEBUG (core:437) - Starting localization component.
2014-02-12 20:32:40,221 (-48e0a940) :  INFO (localization:408) - Setting the default locale to en-us
2014-02-12 20:32:40,221 (-48e0a940) :  DEBUG (localization:426) - Loaded en strings
2014-02-12 20:32:40,221 (-48e0a940) :  DEBUG (core:437) - Starting messaging component.
2014-02-12 20:32:40,222 (-48e0a940) :  DEBUG (core:437) - Starting debugging component.
2014-02-12 20:32:40,222 (-48e0a940) :  DEBUG (core:437) - Starting services component.
2014-02-12 20:32:40,222 (-4e4f1490) :  DEBUG (networking:172) - Requesting 'http://127.0.0.1:32400/system/messaging/clear_events/com.plexapp.plugins.trakttv'
2014-02-12 20:32:40,223 (-48e0a940) :  DEBUG (core:437) - Starting myplex component.
2014-02-12 20:32:40,225 (-48e0a940) :  DEBUG (core:437) - Starting notifications component.
2014-02-12 20:32:40,364 (-48e0a940) :  DEBUG (accessor:68) - Creating a new model access point for provider com.plexapp.plugins.trakttv in namespace 'metadata'
2014-02-12 20:32:40,368 (-48e0a940) :  DEBUG (networking:172) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/resourceHashes'
2014-02-12 20:32:40,851 (-4e4f1490) :  DEBUG (services:265) - Plug-in is not daemonized - loading services from system
2014-02-12 20:32:40,851 (-48e0a940) :  DEBUG (runtime:1108) - Created a thread named 'load_all_services'
2014-02-12 20:32:40,853 (-4e4f1490) :  DEBUG (networking:172) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_'
2014-02-12 20:32:40,853 (-48e0a940) :  DEBUG (runtime:1108) - Created a thread named 'get_server_info'
2014-02-12 20:32:40,854 (-4f879490) :  DEBUG (networking:172) - Requesting 'http://127.0.0.1:32400'
2014-02-12 20:32:40,855 (-48e0a940) :  DEBUG (core:149) - Finished starting framework core
2014-02-12 20:32:40,856 (-48e0a940) :  DEBUG (core:547) - Loading plug-in code
2014-02-12 20:32:40,879 (-4f879490) :  DEBUG (core:525) - Machine identifier is 2732c823e1f815d7ca02f27d9ff23e8f5122da2b
2014-02-12 20:32:40,879 (-4f879490) :  DEBUG (core:526) - Server version is 0.9.8.18.290-11b7fdd
2014-02-12 20:32:40,935 (-48e0a940) :  DEBUG (core:553) - Finished loading plug-in code
2014-02-12 20:32:41,103 (-48e0a940) :  INFO (helpers:129) - Using 'simplejson' module for JSON serialization
2014-02-12 20:32:41,159 (-4e4f1490) :  DEBUG (services:362) - Loaded services
2014-02-12 20:32:41,243 (-4eeb5490) :  DEBUG (services:438) - No shared code to load
2014-02-12 20:32:41,983 (-48e0a940) :  DEBUG (runtime:640) - Adding a prefix handler for 'trakt' ('/applications/trakttv')
2014-02-12 20:32:41,986 (-48e0a940) :  INFO (datakit:93) - Loaded the dictionary file
2014-02-12 20:32:41,986 (-48e0a940) :  INFO (header:12) - ==================================================
2014-02-12 20:32:41,986 (-48e0a940) :  INFO (header:8) - | Plex-Trakt-Scrobbler
2014-02-12 20:32:41,986 (-48e0a940) :  INFO (header:8) - | https://github.com/trakt/Plex-Trakt-Scrobbler
2014-02-12 20:32:41,987 (-48e0a940) :  INFO (header:12) - --------------------------------------------------
2014-02-12 20:32:41,987 (-48e0a940) :  INFO (header:8) - | Current Version: v0.7.13.2-master
2014-02-12 20:32:41,987 (-48e0a940) :  INFO (header:12) - --------------------------------------------------
2014-02-12 20:32:41,988 (-48e0a940) :  INFO (header:8) - | core.eventing
2014-02-12 20:32:41,988 (-48e0a940) :  INFO (header:8) - | core.header
2014-02-12 20:32:41,988 (-48e0a940) :  INFO (header:8) - | core.helpers
2014-02-12 20:32:41,988 (-48e0a940) :  INFO (header:8) - | core.network
2014-02-12 20:32:41,989 (-48e0a940) :  INFO (header:8) - | core.plugin
2014-02-12 20:32:41,989 (-48e0a940) :  INFO (header:8) - | core.trakt
2014-02-12 20:32:41,989 (-48e0a940) :  INFO (header:8) - | core.update_checker
2014-02-12 20:32:41,989 (-48e0a940) :  INFO (header:8) - | data.client
2014-02-12 20:32:41,990 (-48e0a940) :  INFO (header:8) - | data.dict_object
2014-02-12 20:32:41,990 (-48e0a940) :  INFO (header:8) - | data.user
2014-02-12 20:32:41,990 (-48e0a940) :  INFO (header:8) - | data.watch_session
2014-02-12 20:32:41,990 (-48e0a940) :  INFO (header:8) - | plex.media_server
2014-02-12 20:32:41,991 (-48e0a940) :  INFO (header:8) - | pts.activity
2014-02-12 20:32:41,991 (-48e0a940) :  INFO (header:8) - | pts.activity_logging
2014-02-12 20:32:41,991 (-48e0a940) :  INFO (header:8) - | pts.activity_websocket
2014-02-12 20:32:41,991 (-48e0a940) :  INFO (header:8) - | pts.scrobbler
2014-02-12 20:32:41,991 (-48e0a940) :  INFO (header:8) - | pts.scrobbler_logging
2014-02-12 20:32:41,992 (-48e0a940) :  INFO (header:8) - | pts.scrobbler_websocket
2014-02-12 20:32:41,992 (-48e0a940) :  INFO (header:8) - | pts.session_manager
2014-02-12 20:32:41,992 (-48e0a940) :  INFO (header:12) - ==================================================
2014-02-12 20:32:41,992 (-48e0a940) :  DEBUG (__init__:83) - Cleaning up stale or invalid sessions
2014-02-12 20:32:41,992 (-48e0a940) :  DEBUG (__init__:113) - Finished cleaning up
2014-02-12 20:32:41,994 (-48e0a940) :  INFO (datakit:131) - Saved the dictionary file
2014-02-12 20:32:41,995 (-48e0a940) :  DEBUG (preferences:256) - Loaded preferences from DefaultPrefs.json
2014-02-12 20:32:41,996 (-48e0a940) :  DEBUG (preferences:178) - Loaded the user preferences for com.plexapp.plugins.trakttv
2014-02-12 20:32:41,996 (-48e0a940) :  INFO (__init__:46) - Autostart scrobbling
2014-02-12 20:32:41,997 (-48e0a940) :  INFO (__init__:52) - Automatically sync new Items to Collection
2014-02-12 20:32:41,997 (-48e0a940) :  INFO (__init__:60) - Will autosync in 1 minute
2014-02-12 20:32:41,998 (-48e0a940) :  DEBUG (runtime:1141) - Scheduled a timed thread named 'SyncTrakt'
2014-02-12 20:32:41,998 (-48e0a940) :  DEBUG (network:108) - Requesting 'http://192.168.1.7:32400/' (xml) [retry, timeout: 3]
2014-02-12 20:32:42,000 (-48e0a940) :  INFO (__init__:66) - Server Version is 0.9.8.18.290-11b7fdd
2014-02-12 20:32:42,001 (-48e0a940) :  DEBUG (runtime:1108) - Created a thread named 'run'
2014-02-12 20:32:42,001 (-4f879490) :  DEBUG (network:108) - Requesting 'http://192.168.1.7:32400/status/sessions' (xml) [retry, timeout: 3]
2014-02-12 20:32:42,003 (-5023d490) :  DEBUG (network:108) - Requesting 'http://pts.skipthe.net/api/ping' (json) [len(data): 127, data_type: 'json']
2014-02-12 20:32:42,003 (-48e0a940) :  DEBUG (runtime:1108) - Created a thread named 'run'
2014-02-12 20:32:42,004 (-48e0a940) :  INFO (core:598) - Started plug-in
2014-02-12 20:32:42,005 (-4f879490) :  DEBUG (network:108) - Requesting 'http://192.168.1.7:32400/' (xml) [retry, timeout: 3]
2014-02-12 20:32:42,005 (-48e0a940) :  DEBUG (socketinterface:160) - Starting socket server
2014-02-12 20:32:42,007 (-48e0a940) :  DEBUG (runtime:1108) - Created a thread named 'start'
2014-02-12 20:32:42,008 (-48e0a940) :  INFO (socketinterface:184) - Socket server started on port 55926
2014-02-12 20:32:42,008 (-4f879490) :  INFO (activity:56) - Picked method WebSocket
2014-02-12 20:32:42,009 (-48e0a940) :  INFO (pipeinterface:25) - Entering run loop
2014-02-12 20:32:42,009 (-48e0a940) :  DEBUG (runtime:717) - Handling request GET /:/prefixes
2014-02-12 20:32:42,011 (-48e0a940) :  DEBUG (runtime:814) - Found route matching /:/prefixes
2014-02-12 20:32:42,013 (-48e0a940) :  DEBUG (runtime:915) - Response: [200] MediaContainer, 447 bytes
2014-02-12 20:32:42,907 (-5023d490) :  DEBUG (update_checker:94) - Up to date
2014-02-12 20:32:42,908 (-5023d490) :  DEBUG (update_checker:103) - Next update check scheduled to happen in 89220 seconds
2014-02-12 20:32:47,000 (-4eeb5490) :  INFO (datakit:131) - Saved the dictionary file
2014-02-12 20:33:41,998 (-4e4f1490) :  DEBUG (runtime:1147) - Starting timed thread named 'SyncTrakt'
2014-02-12 20:33:41,999 (-4e4f1490) :  INFO (sync:80) - Not enough time since last sync, breaking!
eknee commented 10 years ago

This is what I see when I directly access the URL from the logs (http://192.168.1.7:32400/)

<MediaContainer size="13" friendlyName="KNAS PLEX" machineIdentifier="2732c823e1f815d7ca02f27d9ff23e8f5122da2b" multiuser="1" myPlex="1" myPlexMappingState="mapped" myPlexSigninState="ok" myPlexUsername="eknee1417@gmail.com" platform="Linux" platformVersion=" (#4 SMP Sat Nov 23 11:30:35 PST 2013)" requestParametersInCookie="1" sync="1" transcoderActiveVideoSessions="0" transcoderAudio="1" transcoderVideo="1" transcoderVideoBitrates="64,96,208,320,720,1500,2000,3000,4000,8000,10000,12000,20000" transcoderVideoQualities="0,1,2,3,4,5,6,7,8,9,10,11,12" transcoderVideoResolutions="128,128,160,240,320,480,768,720,720,1080,1080,1080,1080" updatedAt="1392259155" version="0.9.8.18.290-11b7fdd">
<Directory count="1" key="applications" title="applications"/>
<Directory count="1" key="channels" title="channels"/>
<Directory count="1" key="clients" title="clients"/>
<Directory count="1" key="library" title="library"/>
<Directory count="1" key="music" title="music"/>
<Directory count="1" key="playQueues" title="playQueues"/>
<Directory count="1" key="player" title="player"/>
<Directory count="1" key="playlists" title="playlists"/>
<Directory count="1" key="search" title="search"/>
<Directory count="1" key="servers" title="servers"/>
<Directory count="1" key="system" title="system"/>
<Directory count="1" key="transcode" title="transcode"/>
<Directory count="2" key="video" title="video"/>
</MediaContainer>
fuzeman commented 10 years ago

I can't actually see any timeout in that log file. [retry, timeout: 3] just means the request would retry if after 3 seconds no response is received, this doesn't mean it's actually timing out.

You shouldn't need to change the request host, localhost should point to 127.0.0.1 and connect to the media server the plugin is installed on.

eknee commented 10 years ago

k, i thought that meant it was timing out. So it appears to be working then but I'm not seeing trakt getting updated with my existing collection. Its grabbing new things as they come down with sab but not uploading data about the existing.

fuzeman commented 10 years ago

What does the log file show when you trigger the sync?

Note, you do have to trigger syncing manually in the current master branch (automatic syncing is in the beta and is getting closer to stable).

Triggering a sync

1. Open the channel

2. Open the "Sync" menu

3. Click this button

eknee commented 10 years ago 
2014-02-12 22:40:58,969 (-4eeb5490) :  DEBUG (network:108) - Requesting 'http://api.trakt.tv/show/episode/seen/ba5aa61249c02dc5406232da20f6e768f3c82b28' (json) [len(data): 2817, data_type: 'json', retry]
2014-02-12 22:41:00,562 (-4eeb5490) :  DEBUG (network:108) - Requesting 'http://api.trakt.tv/show/episode/seen/ba5aa61249c02dc5406232da20f6e768f3c82b28' (json) [len(data): 6326, data_type: 'json', retry]
2014-02-12 22:41:03,632 (-4eeb5490) :  DEBUG (network:108) - Requesting 'http://api.trakt.tv/show/episode/seen/ba5aa61249c02dc5406232da20f6e768f3c82b28' (json) [len(data): 983, data_type: 'json', retry]
2014-02-12 22:41:04,323 (-4eeb5490) :  DEBUG (network:108) - Requesting 'http://api.trakt.tv/show/episode/seen/ba5aa61249c02dc5406232da20f6e768f3c82b28' (json) [len(data): 3219, data_type: 'json', retry]
2014-02-12 22:41:06,437 (-4eeb5490) :  DEBUG (network:108) - Requesting 'http://api.trakt.tv/show/episode/seen/ba5aa61249c02dc5406232da20f6e768f3c82b28' (json) [len(data): 2414, data_type: 'json', retry]
2014-02-12 22:41:07,806 (-4eeb5490) :  DEBUG (network:108) - Requesting 'http://api.trakt.tv/show/episode/seen/ba5aa61249c02dc5406232da20f6e768f3c82b28' (json) [len(data): 300, data_type: 'json', retry]
2014-02-12 22:41:08,229 (-4eeb5490) :  DEBUG (network:108) - Requesting 'http://api.trakt.tv/show/episode/seen/ba5aa61249c02dc5406232da20f6e768f3c82b28' (json) [len(data): 350, data_type: 'json', retry]
eknee commented 10 years ago

Ahhhh, wait. Its working.....the first time it timed out for some reason but now its rolling.