Horizon: Delayed at is Wrong

[Perh0rd]

• Horizon Version: 3.7.1
• Laravel Version: 5.8
• PHP Version: 7.3
• Redis Driver & Version: predis 5.2
• Database Driver & Version: Mysql8.0

Description:

When we hover the mouse on a delayed tag to a delayed job, and when we click to see the detail of the job, the "Delayed Until" time is wrong.

• Redis time is ok
• Host time is ok
• Laravel timezone is ok

Steps To Reproduce:

Launch job
Go to horizon and check

Screen : https://anopetia.tinytake.com/tt/NDA3NTQ4Nl8xMjUzNTMxMw

[ramonvic]

Same Here

[themsaid]

I can't replicate this:

[Perh0rd]

Any idea where it can come from ? The thing which is weird is that the time inside the JSON data is ok .

And the job are dispatched well.

It’s really on the horizon dashboard it does not reflect the correct information .

[brunogaspar]

Just a wild guess, but the .local() call on this line https://github.com/laravel/horizon/blob/3.0/resources/js/screens/recentJobs/job.vue#L107 could cause it, but again, just a guess, i haven't tried to reproduce this.

[Perh0rd]

Local time of the computer is the same as the server .

[Perh0rd]

Completed at is ok :

[brunogaspar]

Both uses different methods to present the date for some reason.

This could be clearly cleaned up, but in general that's the main difference i see.

[themsaid]

Please share the response coming from the server for the job view screen.

[Perh0rd]

@themsaid What do you mean « for the job view screen »?

[brunogaspar]

So i did a test locally to reproduce it and the line i mentioned above is the culprit.

The reason for that is .local() makes the date into your current timezone, not the server, which was my initial assumption.

How i reproduced, dispatched a job with a delay of 3 hours then changed my timezone to Seattle from Lisbon to see the problem.

Now, the proper fix it really depends, should all dates respect the user timezone or the server timezone?
The later seems the norm for the majority of the dates, but 🤷‍♂

[Perh0rd]

@brunogaspar Thank you for this precision . However my timezone is the same as the server . I’m EST both on server and my computer , so why the date and time is shown for me with -5 hours from my current TZ?

[brunogaspar]

hmm that i don't really know, sorry, but removing that .local() fixed it on my reproducible case.

Are you able to try the removal of that piece of code and see if that addresses it?

[Perh0rd]

I confirm this is link to the time of the machine. I change the timezone of my computer and so does the time of delayed until change. However, even If i’m doing this the time reflected by the local() function does not even match the time of the local machine, which is a problem.

Here is a short video of the problem : https://anopetia.tinytake.com/tt/NDA3Nzk5OV8xMjU0MjU0Nw

Interesting fact after looking at the video is, the push at and completed at seems to define the time based on the local machine also, but properly.

[brunogaspar]

I guess it's because it first converts it to UTC then to your timezone, the other dates do not use the same method to format them, that's why they behave differently (or correctly) hehe :)

[Perh0rd]

Yes, so @themsaid I guess we can consider this as a bug.?

[themsaid]

@Perh0rd Please share the response from the screen where you preview the job details, the one where you see the wrong time. Check the Networking tab in the browser console and copy/paste the response.

[themsaid]

@brunogaspar removing .local() broke it on my local machine and forge server. So in order for us to make a change that doesn't break it on someone else's machine we need to know why you're having a different outcome than mine.

[brunogaspar]

Elaborate what it broke? Any error? Different result?

Considering that the way this is formatted compared to the other fields, this feels already wrong and should be tweaked.

[themsaid]

@brunogaspar removing local() causes the date to be wrong. With local() the date looks correct on my local machine and forge server.

I can't replicate the issue as I stated here: https://github.com/laravel/horizon/issues/771#issuecomment-588139632

[brunogaspar]

Ya i saw it.

Have you changed your machine timezone?

What timezone is on your Laravel application?

Is the job in a different timezone as on @Perh0rd end?

I managed to reproduce with little steps, being my app and my job still on UTC but with a bit more changes, like, changing the timezone of the entire app to something, it also shows erroneous date because that line first converts the date to UTC then to whatever your machine timezone using the .local(), which in the end does not seem to be the correct behaviour, since it's not being formatted as the other dates aka using the formatDate() method.

I can investigate this a bit further later today if you don't manage to do so :)

[themsaid]

Can someone please share the response coming from the server in the Horizon screen? 🙂 Thanks!

[brunogaspar]

Sure, i'll try to reply with 2 different responses later today no problem.

Thanks for looking at this!

[themsaid]

You can also share the data that you see for the job in Horizon's UI:

[Perh0rd]

Here the response:

{ notifiables: { class: "App\Models\Users\User", id: 40, relations: [ ], connection: "mysql" }, notification: { byPassPush: false, id: "2b4572b1-b110-4187-a140-68b32f6b8ef9", locale: null, connection: null, queue: null, chainConnection: null, chainQueue: null, delay: { date: "2020-02-19 15:23:11.946210", timezone_type: 3, timezone: "AMERICA/TORONTO" }, chained: [ ] }, channels: [ "mail" ], tries: null, timeout: null, connection: null, queue: null, chainConnection: null, chainQueue: null, delay: { date: "2020-02-19 15:23:11.946210", timezone_type: 3, timezone: "AMERICA/TORONTO" }, chained: [ ] }

[Perh0rd]

Complete response :

{"id":"616","connection":"redis","queue":"default","name":"App\\Notifications\\ShipmentSendPendingReminder","status":"pending","payload":{"displayName":"App\\Notifications\\ShipmentSendPendingReminder","job":"Illuminate\\Queue\\CallQueuedHandler@call","maxTries":null,"delay":null,"timeout":null,"timeoutAt":null,"data":{"commandName":"Illuminate\\Notifications\\SendQueuedNotifications","command":"O:48:\"Illuminate\\Notifications\\SendQueuedNotifications\":11:{s:11:\"notifiables\";O:45:\"Illuminate\\Contracts\\Database\\ModelIdentifier\":4:{s:5:\"class\";s:21:\"App\\Models\\Users\\User\";s:2:\"id\";i:40;s:9:\"relations\";a:0:{}s:10:\"connection\";s:5:\"mysql\";}s:12:\"notification\";O:45:\"App\\Notifications\\ShipmentSendPendingReminder\":9:{s:10:\"byPassPush\";b:0;s:2:\"id\";s:36:\"f7c781ef-7a7b-4260-8fd0-705b57f23a6a\";s:6:\"locale\";N;s:10:\"connection\";N;s:5:\"queue\";N;s:15:\"chainConnection\";N;s:10:\"chainQueue\";N;s:5:\"delay\";O:13:\"Carbon\\Carbon\":3:{s:4:\"date\";s:26:\"2020-02-20 08:58:23.976917\";s:13:\"timezone_type\";i:3;s:8:\"timezone\";s:15:\"AMERICA\/TORONTO\";}s:7:\"chained\";a:0:{}}s:8:\"channels\";a:1:{i:0;s:4:\"mail\";}s:5:\"tries\";N;s:7:\"timeout\";N;s:10:\"connection\";N;s:5:\"queue\";N;s:15:\"chainConnection\";N;s:10:\"chainQueue\";N;s:5:\"delay\";r:15;s:7:\"chained\";a:0:{}}"},"id":"616","attempts":0,"type":"notification","tags":[],"pushedAt":"1582206803.9781"},"exception":null,"failed_at":null,"completed_at":null,"retried_by":null,"reserved_at":null,"index":0}

[themsaid]

fixed in https://github.com/laravel/horizon/commit/aa6935737c093c9abae26f7ebe16980b4b7803e9

Thanks everyone