Date Played, Date Added, log times are wrong

Server Version#: 1.24.5.5173
Player Version#: Various (Web=4.68.0, Android=8.25.0.28665)
DS218+ running DSM 6.2.4-25556 Update 2 (latest DSM prior to 7)

Update: cleaning up this top post to be more clear about potential causes and symptoms.

Issues:

  1. Data listed in Play History for Date Played is very wrong. See screenshot 1 for example; all of the items displayed were actually watched on 10/26/21 in the evening (ie, a ~day before the event(s) that potentially caused the issues). This also had a cascading effect of making it seem like items played after the issue-causing event(s) were not being displayed at all; but in some subsequent investigation, they are there, just being sorted unexpectedly - see screenshot 2.
  2. Date Added data is behaving strangely. I noticed a movie that I uploaded after the issue-causing event(s) wasn’t appearing in “Recommended” as the first of Recently Added. At first I thought maybe it just hadn’t been detected, but it’s in my library - and in trying to suss out the Date Added (which i did by going to the Movies library > Recommended > click on "Recently Added" heading - which then sorts the library by Date Added and displays the Date Added underneath the movie in Grid view) it appears at the very end with “A day ago” - and every single other movie is showing “a few seconds ago” (Aside from the new movie, they appear to be showing in the correct order in which they were added, in both this view and in the Recommended view)
  3. PMS’ own clock seems wrong. Two pieces of evidence for this: Console log output timestamps, and the title of the server logs .zip file. However, this doesn’t appear fully consistent because the movie I uploaded after the issue-causing event(s) did display the correct time for Date Added.
  • Console log: Had a look at the Console via Settings / Manage > Console on 10/28/2021 @ 830p EST (my local time) and the output timestamps of the “real time” logging are displaying as November 15, 1964.
  • Log file title: Exported the server logs via Settings / Manage > Troubleshooting > Download Logs. All the files in the downloaded .zip package have Date Modified times in the year 2044 or 2033, and the title of the .zip is “Plex Media Server Logs_1964-11-15_23-37-33.zip” - attached below (the first log uploaded had verbose enabled, but keeping it in case it has relevant data since the logs were captured a day or so apart)

Potential Causes:

  1. Updated to PMS 1.24.5.5173 on 10/27 ~830p EST.
  2. Approximately 5 min after updating PMS, I was poking around on my Synology and noticed the time in the Synology logs was an hour off, so I changed the timezone (It was on GMT-05:00 Bogota, Lima, Quito, Rio Branco, and I changed it to GMT-05:00 Eastern Time US & Canada). I think I also forced it to synchronize with NTP server (time.google.com) at that time.

Additional Context / Pleas for help :slight_smile:

  • I know the issue began occurring the night of 10/27 because I view the Date Played data fairly regularly and it was fine earlier in the day and prior.

  • The biggest headache/impact is not having newly-added content showing at the front of the “Recently Added” widget in the Recommended screen - users won’t be able to easily see that content, or even be aware of it.

  • Would appreciate any ideas for troubleshooting this and/or assurances of what steps to take or not take in the immediate.

  • For now, I’m hesitant to add new content or restart PMS for fear of making the problem worse / permanently hosed (assuming it is not already)

  • Not sure if it’s the update or the timezone change that could’ve caused (presumably) all of these things (am leaning towards the TZ change), but in terms of a fix, I’m wondering if either of the following would help or hurt:
    Restarting PMS (haven’t done since bringing it back online after the update / before the timezone change)
    Changing the Synology timezone back

Thank you for reading and providing any advice.


Screenshot 1: Play History when sorting Play time “Descending” (ie the default, would expect most recently played at the top). The items shown were the most recently played prior to update.

Screenshot 2: Play History when sorting Play Time “Ascending” (opposite of the sorting in first screenshot). Highlighted items show their proper played times (three on 10/27 in the evening and one just now). The ones sorted above those were watched sometime in early 2020, and the Jan 1, 1939 was watched a few months ago.
image

Log dump from previous post: Plex Media Server Logs_1964-11-15_23-37-33.zip (4.1 MB)

Found this thread from 2018 where someone else had some Date Added issues, which makes me think its way more likely my issues are stemming from updating the Synology server time than the update :slight_smile:

Though that user’s issues were for different platforms, reading some of the comments from @ChuckPa and @OttoKerner were helpful for me in trying to understand how PMS ascertains (at least) Date Added data:

“PMS doesn’t go by the file or directory date. It goes by the date it was scanned and added to PMS.”

Which makes me wonder if changing the server back to the time zone it was in would “fix” the problems, as PMS would parse the timestamps it generated for Date Added properly (since that’s what the server time was in when they were added)

But as for trying to figure out how the server time may impact other time data like Recently Played, and the logging times, towards the main goal of trying to ascertain how I may be able to recover from this, I am sadly at a loss.

Any assistance from the mods would be greatly appreciated.

realized i had verbose on when i dumped these logs, unchecked that setting and just did another dump just now Plex Media Server Logs_1964-11-16_18-24-36.zip (3.9 MB)

Not seeing any sort of reply to a post over several days is very unusual in my experience in these forums - wondering if maybe it was overlooked? Was really hoping @ChuckPa could weigh in here.

thanks for pinging me. Sorry I didn’t see the notification (silly server was out :beers: again)

Whenever you make major changes to system time – Restart the entire box.

PMS picks up the timezone when it starts but does not know to update AFTER starting.

This could be a major issue right here.

I setup my machines to always sync to pool.ntp.org

Thank you for responding!
Ok, so you’re saying my next step should be to restart the entire server? Im inclined to use the same time server to sync as you, so perhaps i will:

  • do a restart
  • confirm the issue is resolved
  • then change the time server, resync,
  • restart the box again

I’m advising.

  1. Make the configuration changes as you intend for it to run.
  2. After all changes have been made –
  3. Restart the NAS;
  • DSM restarts and all its services are in the correct time and timezone
  • PMS, which is dependent on DSM, launches in the correct time and timezone.

Your way will also work provided that final reboot of the NAS is performed and both DSM and PMS come up together in the correct time zone and in sync with the time server.

Well, I had just restarted the NAS (before changing to using pool.ntp.org) before seeing your latest post :grin:
When Plex came back up, the Date Played /added items looked to be proper again - except for items that had been played or added over the last 5 days (ie, while PMS was in the awkward time state) - those items still show played/added as 1964 dates. Not really a huge deal since its just a handful of items but would be cool if fixable; for the Date added item (just a single movie) I’m thinking to just delete it and re-add.

I then changed the NAS to the new time server to sync, restarted the box again, and things are looking good, sans the caveats mentioned above

For those items added – Plex Dance them.

  1. Move it out where PMS can’t see them
  2. Scan files
  3. Empty Trash
  4. Clean Bundles
  5. Move back.

Date added will be today (when you add it back in as fresh)

Never had a reason to do the Plex Dance before! :dancer:
Worked as advertised. Thank you much for coming to the rescue once again!

My pleasure! :wave:

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.