Nothing updated, entity state is tainted.

[TechPerplexed]

Thanks for creating this project, it's what I have been wanting for years now - can't wait for the Trakt integration as well!

I'm having an issue with the webhooks I hope you can help with. As soon I start playing something on any of the services, I'm getting the following error on Emby both when I start playing something and when it finishes:

127.0.0.1 -  17/Apr/2022:20:48:25 +0000 "POST /index.php" 200
response_status: 200 - response_text: "Nothing updated, entity state is tainted." - request_key: "-" - http_request: "POST /?&apikey=xxxxx HTTP/1.1":5 - user_ip: 172.18.0.6 - http_host: watchstate - user_agent: "Emby Server/4.6.7.0"

Jellyfin:

127.0.0.1 -  17/Apr/2022:22:39:13 +0000 "POST /index.php" 200
response_status: 200 - response_text: "Nothing updated, entity state is tainted." - request_key: "xxxxx" - http_request: "POST / HTTP/1.1":5 - user_ip: 172.18.0.8 - http_host: watchstate - user_agent: "Jellyfin-Server/10.7.7"

With Plex, I'm getting a different error:

2022/04/17 20:55:55 [crit] 58#58: *1654 open() "/var/lib/nginx/tmp/client_body/0000000006" failed (13: Permission denied), client: 172.18.0.14, server: , request: "POST /?&apikey=xxxxx HTTP/1.1", host: "watchstate"
response_status: 500 - response_text: "-" - request_key: "-" - http_request: "POST /?&apikey=xxxxx HTTP/1.1":170 - user_ip: 172.18.0.14 - http_host: watchstate - user_agent: "PlexMediaServer/1.25.9.5721-965587f64"

Obviously it's talking to the Webhook because it registers the start/stop action, but what does it mean that the entity state is tainted? And any idea why Plex is giving a permission denied error? Thanks so much :)

Edit: forgot to mention that manually running the import and export commands runs just fine!

[arabcoders]

Hi, Thanks for your report. tainted events are webhook events that we cant really use to update the play state, but interesting enough for us to accept for other information like updated GUID mapping etc. it's normal don't worry about it. I think i need to list this in FAQ.

And any idea why Plex is giving a permission denied error?

I see it's nginx misconfiguration on my part, i should have updated container soon. Thanks for the report.

[arabcoders]

I pushed an update right now it should take 30min for containers to be rebuild, please try to pull the new container then try. Thanks for your report.

[TechPerplexed]

Perfect, thanks! I just updated it and started playing something on Plex, and the error seems gone. I'll have yet to test the sync, since I haven't had a chance yet to watch anything.

However, all is not completely well yet. I watched something on Jellfyfin and it's not synced to Emby. In fact I'm now getting an error

127.0.0.1 - 18/Apr/2022:00:26:54 +0000 "POST /index.php" 400 response_status: 400 - response_text: "JellyfinServer: No supported GUID was given. []" - request_key: "xxxxx" - http_request: "POST / HTTP/1.1":85 - user_ip: 172.18.0.6 - http_host: watchstate - user_agent: "Jellyfin-Server/10.7.7"

Here are my .env values:

┌────────────────┬──────────────────────┐
│ Key            │ Value                │
├────────────────┼──────────────────────┤
│ WS_UID         │ 1000                 │
│ WS_GID         │ 1000                 │
│ WS_TZ          │ America/Phoenix      │
│ WS_CRON_IMPORT │ 1                    │
│ WS_CRON_EXPORT │ 1                    │
│ WS_CRON_PUSH   │ 1                    │
└────────────────┴──────────────────────┘

Again, thanks for providing this much needed project!

[arabcoders]

@TechPerplexed Please take a look at https://github.com/ArabCoders/watchstate/issues/51 if it solves your current problem. edit metadata on the played item and make sure it has external ids.

[TechPerplexed]

Ok :) It was the show Quantum Leap and it does appear to have all the metadata complete:

https://imgur.com/a/4vzBRJY

Edit; give me a day or two to see how it behaves from Plex/Emby to the other two services... if that works fine, it's probably Jellyfin being awkward.

[arabcoders]

Ok :) It was the show Quantum Leap and it does appear to have all the metadata complete:

https://imgur.com/a/4vzBRJY

Alright this eliminates one possible problem. could you also please check that you have "Send All Properties (ignores template)" ticked in your webhook settings? if you do have it enabled then please update your webhook url to include this rdebug=1 for example http://localhost/?apikey=your_api_token&rdebug=1

this will generate request dump in /config/webhook/request.time.json

i would like to see the the log. just make sure to remove your identifiable information.

[TechPerplexed]

Yes, it's ticked. I wasn't clear though whether to tick my username (there was nothing in the documentation about that), so I tried with it unticked and ticked. That didn't make a difference.

As for the debug information, sure thing, but unfortunately I won't be able to do this tonight. Will update this thread tomorrow with the requested information though :)

[arabcoders]

For the user if you just want to limit the calls for specific user then you should tick your username.

No problem take your time.

[TechPerplexed]

Here you go: - there were numerous files so I hope I picked one you can use.

I waited a few hours and nothing that was watched is synced back to Emby or Plex. Tonight we'll be using Plex and see if it syncs. I feel we're close, because manually syncing works just fine... it's just the import, export and push cron that seem stubborn!

[arabcoders]

Thanks, this log looks fine to me, could you pull latest container and do run the following commad, it should show you if there are events that has been proceed look at WH Event column.

$ docker exec -ti watchstate console db:list

and for tasks scheduler, you can run

$ docker exec -ti watchstate console scheduler:list

to see if tasks are enabled or not.

and run this commad to see your queued events.

$ docker exec -ti watchstate console state:push --queue-show

[TechPerplexed]

Right, running docker exec -ti watchstate console db:list gives "There are no commands defined in the "db" namespace."

The command docker exec -ti watchstate console scheduler:list gives

+--------+--------------+-------------+---------------------------+---------------+
| Name   | Command      | Run As      | Run At                    | In Background |
+--------+--------------+-------------+---------------------------+---------------+
| import | state:import | App Command | 2022-04-18T23:00:00+00:00 | Yes           |
| export | state:export | App Command | 2022-04-18T22:30:00+00:00 | Yes           |
| push   | state:push   | App Command | 2022-04-18T22:30:00+00:00 | Yes           |
| cache  | state:cache  | App Command | 2022-04-19T00:00:00+00:00 | Yes           |
+--------+--------------+-------------+---------------------------+---------------+

And finally, docker exec -ti watchstate console state:push --queue-show gives a long list... I have truncated it a little but can post the whole thing if you with ^_^

+------+---------+---------------------------+----------+------------------------------------+---------------------+---------+
| ID   | Type    | Date                      | Via      | Main Title                         | Year | Episode      | Watched |
+------+---------+---------------------------+----------+------------------------------------+---------------------+---------+
| 7060 | movie   | 2022-04-18T00:44:01+00:00 | Plex     | Sabrina                            | ( 1995 )            | No      |
| 6847 | episode | 2022-04-18T01:22:19+00:00 | Jellyfin | Tabitha                            | ( 1977 ) - S01E03   | Yes     |
| 7061 | movie   | 2022-04-18T04:03:56+00:00 | Jellyfin | The Haunted Palace                 | ( 1963 )            | No      |
(left a lot of lines out)
| 6794 | episode | 2022-04-18T20:40:33+00:00 | Jellyfin | Quantum Leap                       | ( 1989 ) - S02E06   | Yes     |
| 6795 | episode | 2022-04-18T22:23:02+00:00 | Jellyfin | Quantum Leap                       | ( 1989 ) - S02E07   | No      |
| 6821 | episode | 2022-04-18T22:23:39+00:00 | Jellyfin | Star Trek: Picard                  | ( 2020 ) - S02E07   | No      |
+------+---------+---------------------------+----------+------------------------------------+---------------------+---------+

[arabcoders]

It seems to be working fine, except the task scheduler, i made an updates in latest container, if you can make sure you are at the latest one it will give you access to the new db:list command. as you see from the queue, your events are making it. please update to lastest container and restart and see if you have access to db:list command, if you do it means you are on latest container.

[TechPerplexed]

Oh, ok, here's the output now (had to restart the container after updating):

┌──────┬─────────┬──────────┬────────────────────────┬───────────────────┬───────────────────────────┬─────────┬───────────────┐
│ ID   │ Type    │ Via      │ Main Title             │ Year | Episode    │ Date                      │ Watched │ WH Event      │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 6821 │ Episode │ Jellyfin │ Star Trek: Picard      │ ( 2020 ) - S02E07 │ 2022-04-18T22:23:39+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 6795 │ Episode │ Jellyfin │ Quantum Leap           │ ( 1989 ) - S02E07 │ 2022-04-18T22:23:02+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 6794 │ Episode │ Jellyfin │ Quantum Leap           │ ( 1989 ) - S02E06 │ 2022-04-18T20:40:33+00:00 │ Yes     │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7193 │ Episode │ Jellyfin │ Dad's Army             │ ( 1968 ) - S01E05 │ 2022-04-18T16:14:55+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7192 │ Episode │ Jellyfin │ Dad's Army             │ ( 1968 ) - S01E04 │ 2022-04-18T16:14:55+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7191 │ Episode │ Jellyfin │ Dad's Army             │ ( 1968 ) - S01E03 │ 2022-04-18T16:14:52+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7190 │ Episode │ Jellyfin │ The Carol Burnett Show │ ( 1967 ) - S01E27 │ 2022-04-18T14:05:31+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7189 │ Episode │ Jellyfin │ The Carol Burnett Show │ ( 1967 ) - S01E25 │ 2022-04-18T14:05:27+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7188 │ Episode │ Jellyfin │ The Carol Burnett Show │ ( 1967 ) - S01E22 │ 2022-04-18T14:05:24+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7187 │ Episode │ Jellyfin │ The Carol Burnett Show │ ( 1967 ) - S01E21 │ 2022-04-18T14:05:23+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7186 │ Episode │ Jellyfin │ The Carol Burnett Show │ ( 1967 ) - S01E19 │ 2022-04-18T14:05:22+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7185 │ Episode │ Jellyfin │ The Carol Burnett Show │ ( 1967 ) - S01E18 │ 2022-04-18T14:05:21+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7184 │ Episode │ Jellyfin │ The Carol Burnett Show │ ( 1967 ) - S01E16 │ 2022-04-18T14:05:20+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7183 │ Episode │ Jellyfin │ The Carol Burnett Show │ ( 1967 ) - S01E13 │ 2022-04-18T14:05:12+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7182 │ Episode │ Jellyfin │ The Carol Burnett Show │ ( 1967 ) - S01E12 │ 2022-04-18T14:05:11+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7181 │ Episode │ Jellyfin │ The Carol Burnett Show │ ( 1967 ) - S01E11 │ 2022-04-18T14:05:04+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7180 │ Episode │ Jellyfin │ The Carol Burnett Show │ ( 1967 ) - S01E08 │ 2022-04-18T14:05:03+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7179 │ Episode │ Jellyfin │ The Carol Burnett Show │ ( 1967 ) - S01E06 │ 2022-04-18T14:05:01+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7178 │ Episode │ Jellyfin │ Dad's Army             │ ( 1968 ) - S01E06 │ 2022-04-18T13:21:26+00:00 │ No      │ UserDataSaved │
├──────┼─────────┼──────────┼────────────────────────┼───────────────────┼───────────────────────────┼─────────┼───────────────┤
│ 7177 │ Episode │ Jellyfin │ Cosmos (2014)          │ ( 2014 ) - S01E13 │ 2022-04-18T13:21:07+00:00 │ No      │ UserDataSaved │
└──────┴─────────┴──────────┴────────────────────────┴───────────────────┴───────────────────────────┴─────────┴───────────────┘

[arabcoders]

That's perfect, it seems your events are registering correctly. just give it 10 mins for the scheduler to run. in about 15mins try running

docker exec -ti watchstate console state:push --queue-show

if it's empty it means the task scheduler has run and you should start having logs in /config/logs/crons/

[TechPerplexed]

Ok - will report back in a bit :) Do I have to enable a particular log? I don't think I have any enabled right now.

[arabcoders]

No worries, The task scheduler automatically logs so dont worry about it you should see new logs entries in the directory i mentioned in a bit

out of interest if you run docker exec -ti watchstate console ps x do you see a process called crond?

[TechPerplexed]

Thanks. Ok, so if I run that, I'm getting "Command "ps" is not defined."

The output of docker exec -ti watchstate console state:push --queue-show is empty now, and so is the /config/logs/cron folder (so far)

[arabcoders]

Np, that mean the task scheduler has run, can you check your watch state in related media servers?

[TechPerplexed]

Whaaa, I was having such high hopes, but alas... the episodes that were watched this afternoon are not yet showing as watched in Plex and Emby :(

[arabcoders]

do you have discord? can you add me "...." that would speed this up :-)

[TechPerplexed]

I don't, but can get that. Unfortunately however I have a meeting coming up in 5 minutes so I'll have to take a raincheck on this. I have saved your ID so you can delete that if you wish :)

[arabcoders]

Alright, for reference, i want you to watch something now on any of those media servers that you have webhook on, once you finish run docker exec -ti watchstate console state:push --queue-show if it shows the item in the queue then everything is working fine, and if some items dont make it check /config/logs/app.log it should tell you why it was rejected.

[TechPerplexed]

Sorry I had to run earlier. I quickly skimmed through an episode to get to the end, and showed in the queue immediately afterwards:

+------+---------+---------------------------+----------+--------------+-------------------+---------+
| ID   | Type    | Date                      | Via      | Main Title   | Year | Episode    | Watched |
+------+---------+---------------------------+----------+--------------+-------------------+---------+
| 6795 | episode | 2022-04-19T01:01:30+00:00 | Jellyfin | Quantum Leap | ( 1989 ) - S02E07 | Yes     |
+------+---------+---------------------------+----------+--------------+-------------------+---------+

So far, so good.....

Edit: it finished updating.............. anddddddddddddddddddddddd............ believe it or not..... it got synced back to both Plex AND Emby!!!!

We're getting there 😆 Now of course the big question is why it didn't work earlier today?

[TechPerplexed]

Well, tonight we used Plex to watch stuff and it was synced back to Emby and Jellyfin almost instantly. I think we can safely conclude that whatever you did to fix this works :)

Thanks so much for this project, is really nice not having to rely on Trakt any longer!

[arabcoders]

Thanks for your reports. It wasn't working before because the CRON runner was little too picky in the values it consider enabled CRON task, i simplified it and let the tool handle it instead of bash scripting.

[TechPerplexed]

Awesome. Just for your reference, my buddy and I have included it in our upcoming project (not yet fully released)

[arabcoders]

Awesome. Just for your reference, my buddy and I have included it in our upcoming project (not yet fully released)

Thanks, hopefully I'll have v1.0 tagged before then.

[TechPerplexed]

Oh I'm sure it will be. I forgot to mention that part of the container seems to be pulling with every update (even if you run it again right away):

 ⠏ watchstate Pulling                                                                                9.9s
   ⠿ df9b9388f04a Already exists                                                                     0.0s
   ⠿ a60f85627e3d Already exists                                                                     0.0s
   ⠿ 89395091f295 Already exists                                                                     0.0s
   ⠿ 2342a00f1dee Already exists                                                                     0.0s
   ⠿ aa806d3eefd0 Pull complete                                                                      1.8s
   ⠿ 99293c50730b Pull complete                                                                      2.2s
   ⠿ cb6cc00c76a2 Pull complete                                                                      2.8s
   ⠿ 26411232b296 Pull complete                                                                      3.0s
   ⠿ 5d1307e41155 Pull complete                                                                      3.2s
   ⠿ 579a49a849ea Pull complete                                                                      3.4s
[+] Running 38/53 Pull complete     

Probably not a bug, but thought I'd mention it all the same :)

[arabcoders]

Hi, it's not a bug it's because i keep updating the container to fix small issues here and there, it should slow down once i feel it's ready for v1.x