NAV 2013 Job Queue "Earliest Start Date" Issue

bknopp

Hi all,

I've got an issue that has me stumped. I have a Job Queue entry at a client site that currently shows an "Earliest Start Date/Time" of today's date at 10:00 p.m. The client wants the job to run at 2:00 a.m. instead.

The Recurrence section of the card has a "Starting Time" of "2:00:00 AM".

I have set the start time to "tomorrow at 2:00 AM" on two separate occasions. Both times the job ran at 2:00 a.m. as scheduled, but only once. After that, the "Earliest Start Date/Time" changed back to "today at 10:00 PM".

I added the Job Queue settings table to the change logging, and I saw where I changed the start time to 2:00 a.m. There's no entry showing the change back to 10:00 p.m.

I haven't found anything on the internet about this, but that may be an indictment of my Bing-fu :oops:

Any suggestions? ](*,)

OldNavDog

Just a quick thought.

I have found that things running under a (at least the "old") NAS tend to sometimes have a problem getting "updated" data.

Try Disabling, then Re-Enabling, the NAS (I would go so far as to Re-Start the NAV Server Instance), then see if your problem goes away.

You might try putting a COMMIT in the OnClosePage Trigger of the Job Queue Entry Card Page (672), too. You can even get fancy and put a CONFIRM there, in case you are worried about doing a COMMIT. But Job Queue-related code OFTEN has COMMITs...

But with the Earliest Start set to 2 am, AND the "Start Time" set to 2 am, Job Queue just CAN'T just "dream up" 10 pm.

Remember, the Job Queue "scheduling and launch" operations were VASTLY changed in 2013, with HEAVY use of "STARTSESSION". My feeling is there is a Thread that just hasn't gotten the message that the Job Queue Entry has changed.

bknopp

Thanks for the suggestion.

It's a production environment, so I have to schedule the restart over the week-end. I'll check it Monday morning and let y'all know the results.

ara3n

make sure the service tier local time zone is set correctly to your zone.

einsTeIn.NET

I think it couldn't be related to neither not-updated data (because the Earliest Start Datetime was updated, never saw that a record was "half-updated") nor to localization because that would only lead to time shifted behaviour in total, meaning Earliest Start Datetime and Start Time should be both shifted then, not just one of them.

I would have a look at the Job Queue Process table. I don't know how it looks like in 2013 but I could imagine that it somehow holds the values of the old Job Queue Entry. That could lead to a wrong calculation of next starting time based on old values.

OldNavDog

einsTeIn.NET wrote:

I think it couldn't be related to neither not-updated data (because the Earliest Start Datetime was updated, never saw that a record was "half-updated") nor to localization because that would only lead to time shifted behaviour in total, meaning Earliest Start Datetime and Start Time should be both shifted then, not just one of them.

I would have a look at the Job Queue Process table. I don't know how it looks like in 2013 but I could imagine that it somehow holds the values of the old Job Queue Entry. That could lead to a wrong calculation of next starting time based on old values.

Sorry. While I agree that it seems odd to have a half-updated Record, whatever is causing the REAL problem is making it look like that is the case.

However, The concept of the Job Queue Process Table is completely re-vamped in 2013. And besides, it never held anything that affected recalculation of the next Run time for a Job Queue Entry. ALL of the information used to (re)calculate the Earliest Run Time is in the Job Queue Entry table.

OldNavDog

bknopp wrote:

Thanks for the suggestion.

It's a production environment, so I have to schedule the restart over the week-end. I'll check it Monday morning and let y'all know the results.

...and? [-o<

bknopp

... and no joy.

The service tier restart ran as expected, but the "earliest start time" is once again set to 10:00 p.m. I assume that happened when the job queue entry processed, because the job queue log shows that the process fired at 2:00 a.m. as scheduled.

](*,)

I'm delving into the Job Queue Entries table now.

OldNavDog

bknopp wrote:

... and no joy.

The service tier restart ran as expected, but the "earliest start time" is once again set to 10:00 p.m. I assume that happened when the job queue entry processed, because the job queue log shows that the process fired at 2:00 a.m. as scheduled.

](*,)

I'm delving into the Job Queue Entries table now.

Sigh.

How bizarre!

Let me know what you find in that table.

bknopp

"sigh", indeed.

It looks like the "meat" of the process is in Codeunit 448, in method "CalcRunTimeForRecurringJob". To verify that I plan to put some Message() calls in that method, but when I opened the Navision Development I couldn't open the object list, and when I tried to re-open the database I get "Tabledata 2000000001 does not exist". The account manager for this customer is going to investigate the permissions on the login that I have.

I've put the current job queue entry "on hold" and created another one to run the code unit, on the theory that there may be something in the record that's causing the problem. If that fails, I'm going to put some logging calls in CalcRunTimeForRecurringJob to write information to the event log, so that I can see what's going on inside that call. That way I can start back-tracking to find where the 10:00 p.m. time originates.

[edit]

The new Job Queue entry that I created showed the same behavior, so it's time to put Message() calls in "CalcRunTimeForRecurringJob" and write some checkpoints out to the event log. I will continue to keep you posted. I will also welcome any other suggestions/feedback.

bknopp

The debug Messages that I found in the application event log showed that CalcRunTimeForRecurringJob returns the correct date/time. I had a typo on one of the calls due entirely to a brain fart, so I need to recheck tonight, but I'm about 97% confident that the date/time is right coming out of that call.

I _am_ right in thinking that the "top level" logic that handles Job Queue entries is in Code Unit 448 - Job queue Dispatcher, am I not? I see there are other code unites to handle the Job Queue, but 448 is the starting point, correct? I just want to make sure I'm not barking up the wrong tree.

Tell me something (please - anybody - [begging smiley]) - how do I get the current callstack at runtime if I'm not in the debugger? If I had that, I could put the following code in the Earliest Start Date/Time OnValidate() trigger:

CurrentCallstack := FunctionToGetCurrentCallStackAsLongString();
MESSAGE("Earliest Start Date/Time");
MESSAGE(CurrentCallstack);

That way I can just look at the application event log, find the call stack that leads to the incorrect date/time, and go fix it.

ara3n

I responded with correct time zone for service tier. Is that setup correctly?

bknopp

The application and service layer machines are in the same time zone, and their clocks are synchronized. Based on user feedback, I'm confident that the time shown in NAV matches the time according to the users' clocks.

If you're talking about something else, I'll need more specific guidance on how to pursue your suggestion.

ara3n

bknopp

Ahh. Danke.

The Service tier in my scenario is also set to UTC.

ara3n

well you need to change that to your timezone.

Here is the list.



http://saurav-nav.blogspot.com/2011/05/ ... osoft.html

Rob_Hansen

Not sure if I missed this, but to ask the obvious question... When you're updating the Starting Time on the job queue entry, you're also updating the "Earliest Start Date/Time" to 2am as well, correct? You're not leaving it set as 10pm, right?

bknopp

I've got the "Starting Time" value set to 2:00 a.m. - that value doesn't change.

The problem only affects the "Earliest Start Date/Time" field. I set it to 2:00 a.m. and the next morning it's back to 10:00 p.m.

There are a couple of things I want to do before I change the service settings. The suggestion makes sense, given that 2:00 a.m. UTC is 10:00 p.m. EDT, but if that were the issue I would expect the job to run at 10:00 p.m. the first night, and that still doesn't explain why the "Earliest Start Date/Time" field continues to show 2:00 a.m. until after the job runs. That also makes me wonder what would happen if I left the "Earliest Start Date/Time" field set to 10:00 p.m. - would it change to 6:00 p.m. the next night? I'll set the "Earliest Start" to tomorrow morning at 2:27 a.m. - if you're theory is right then I'll see the time set to 10:27 p.m., right?

I've also thought of something that I think is rather clever, in order to get the call stack whenever the "Earliest Start Date/Time" changes. I create two Code Units, 50001 and 50002. In the OnRun trigger of 50001, I call the Error() function to raise an error; the OnRun trigger in 50002 goes "if not codeunit.run(50001), get the callstack via GetLastErrorCallStack and output it with a message." Then I use CodeUnit.Run(50002) to put the callstack in the application log every time that field changes.

Go on - tell me how brilliant that is. You know you want to. 8)

bknopp

I have finally figured it out \:D/ . The solution bloomed atop the flowering shrubbery that grew from the seed that ara3n planted in my brain about time zones.

As it turns out, the "Earliest Start Date/Time" field displays, and is interpreted as, local time, but the "Starting Time" field displays, and is interpreted as, UTC time. I didn't find that documented anywhere, and if one of you mentioned it in this thread I missed it.

In any event, last night I set "Earliest Start Date/Time" to "04/11/2014 2:15:00 AM" and I set "Starting Time" to "6:07:00 AM". This morning I checked the Job Queue and Job Queue Log entries and found the following:

• The Job Queue Log showed that the job had run at 2:15 a.m. local time. Entries in the application event log on the NAS server machine confirm this time
• The Job Queue Entry item shows an "Earliest Start Date/Time" of "04/14/2014 02:06:00 AM" (the job does not run on week-ends) and a "Starting Time" of "6:07:00 AM"

Thanks to all of you for your assistance, suggestions and patience. I'm still new to Navision, and it was nice not to be made to feel like a "noob".

chihmingtw

Services Default Time Zone:Server Time Zone