I am adding two new accounting log records to allow us to better track a job through its entire lifecycle. These will allow you to see if an attribute was changed during the life of the job instead of just seeing what the job looked like at the end.
1 Like
Thanks for writing up the doc Bhroam, it mostly looks good to me, just one thing, i think the ‘A’ record is already taken:
A
Job was aborted by the server. The message text contains the explanation for why the job was aborted
So, we need a different character for it, maybe a small a ?
I agree with @agrawalravi90, the contents of src/include/acct.h indicate that lowercase a is available.
Thanks for getting this together @bhroam! Using ‘a’ is fine with me. A few minor comments and questions:
-
There is an extraneous ’ in “attribute name '= attribute value”
-
Since we list the attributes the scheduler might alter and not cause a log message, should we also list the server ones? Is this statement to cover things like not logging this message when the pbs_server continuously updates something like a job’s eligible_time, for example? I don’t think the server is continuously calling pbs_alterjob() to update eligible_time as the seconds pass, so it seems that there some subtlety missing in what this is trying to say. Or maybe all of this does not need to be said in the design and we just say the a new record gets logged anytime qalter/pbs_alterjob() is called from outside of a PBS daemon?
-
Related to above, it may be different enough to to not be useful, but we have a related precedent in which job alters/etc. trigger “extra” actions and which do not in when modifyjob hooks get invoked, or not invoked. In the original modifyjob hook implementation the hooks were invoked for ALL job alters, and in version 13 PBS was updated to not invoke the hook for the scheduler altering the job. When the server alters a job the hooks are still invoked (according to the manual, and I see that they are NOT invoked when eligible_time is incremented), but again, I don’t know the server internals well enough to know what that really means. All this is to just point out that this exists, and maybe this same existing determination mechanism could help either with the design and/or implementation.
-
If the two above points does not result in this statement being removed/rewritten, then I should point out that there is an extra “only” in it: “These mostly are read only PBS only attributes.”
-
If your examples are meant to show a realistic chain of events for a job then I think it needs a bit of slight tweaking (or explaining so people like me understand). In the example expanded Q record the job is already submitted with the “afterany:1008.mars@mars” depend, yet there is an example a record showing that it is being set. Is this on purpose?
Additional request for clarification: I believe the design should be explicit about what gets shown in the new record when a value is added to, as in the possible case of job dependencies. Given an example like this, can you show what log messages to expect?
[user1@centos7-2 ~]$ echo "sleep 10000" | qsub -lselect=50
36.centos7-2
[user1@centos7-2 ~]$ echo "sleep 10000" | qsub -lselect=50
37.centos7-2
[user1@centos7-2 ~]$ echo "sleep 10000" | qsub -lselect=50
38.centos7-2
[user1@centos7-2 ~]$ qalter -Wdepend=afterany:37 36
[user1@centos7-2 ~]$ qstat -f 36 | grep depend
depend = afterany:37.centos7-2@centos7-2
Seems clear we’d expect to see this after the above command:
09/27/2019 17:30:19;a;36.centos7-2;depend=afterany:37.centos7-2@centos7-2
What if I then do another qalter and add a different type of dependency?
[user1@centos7-2 ~]$ qalter -Wdepend=afterok:38 36
[user1@centos7-2 ~]$ qstat -f 36 | grep depend
depend = afterany:37.centos7-2@centos7-2,afterok:38.centos7-2@centos7-2
Will I expect to see:
09/27/2019 17:30:19;a;36.centos7-2;depend=afterok:38.centos7-2@centos7-2
or:
09/27/2019 17:30:19;a;36.centos7-2;depend=afterany:37.centos7-2@centos7-2,afterok:38.centos7-2@centos7-2
in the accounting log? I am guessing the later based on the “The attribute value is as you would see it in qstat -f” statement in the current design, but I want to just be sure (and also suggest adding the commands issued that result in the example messages in the design for clarity).
(Note I changed “A” to “a” above in the example logs)
Probably getting to corner case territory now, but what about a case like this where a job attribute is unset via qalter?
[user1@centos7-2 ~]$ echo "sleep 1000" | qsub -A account1
43.centos7-2
[user1@centos7-2 ~]$ qstat -f 43 | grep account
Account_Name = account1
Submit_arguments = -A account1
[user1@centos7-2 ~]$ qalter -A account2 43
[user1@centos7-2 ~]$ qstat -f 43 | grep account
Account_Name = account2
Submit_arguments = -A account1
[user1@centos7-2 ~]$ qalter -A "" 43
[user1@centos7-2 ~]$ qstat -f 43 | grep account
Submit_arguments = -A account1
[user1@centos7-2 ~]$
Seems clear that the qalter than changed the account from account1 to account2 would generate a new log message, but what about the qalter that unsets it? Now saying “The attribute value is as you would see it in qstat -f” might not work, since the attribute is now completely gone from the job/qstat.
@agrawalravi90 @mkaro thanks for the pointer that ‘A’ is taken. I’ve updated it to use ‘a’.
@scc
My intent is that any time the site alters a job attribute, an accounting log record is printed. Inside the server, there are times that internal attribute data structure is modified directly. I was attempting to say these times we would not see a record
I didn’t list the server’s attributes because they are numerous. Basically any internal attribute would be listed. I listed the scheduler attributes because there were just a few. If you want me to come up with the comprehensive list for the server, I will. I said ‘read only PBS only’ trying to indicate the previous statement. I’ll remove the second ‘only’ or rephrase it.
The examples were not a chain of events, but I like that idea. I have modified the examples to show a chain of events.
I’m confused about your qalter of depend example. When I qalter the depend attribute, PBS will replace the old depend value with the new one. If I have a dependency on job 1000 before, and I say -Wdepend=afterany:1001, I’ll only have a dependency on 1001 after. If I want both, I have to add both on the qalter line. Am I wrong here?
I’ve modified the document to say you’ll see ‘UNSET’ if an attribute is unset. This means you’ll see a record that says account=UNSET in your example.
I’ve also added a statement about hooks. A record will be printed if a hook alters a job attribute.
Thanks for incorporating the feedback.
Slightly wrong. You are right in that you cannot add a job to a previously included dependency type, you must specify all of the jobs again to have the effect of adding one. You CAN add a new dependency type to an existing dependency string, though. Look again at my example 3 comments up. The job is submitted with an afterany, and then I qalter it and only specify an afterok and the job gets both.
@scc
I think the behavior your are describing is a bug. Not only is it inconsistent with doing multiple qalters, I don’t think it always happens. I’ve done multiple different things and get different results.
[bmann@nimitz ~]$ qstat
[bmann@nimitz ~]$ qsub -- /bin/sleep 1000
2873.nimitz
[bmann@nimitz ~]$ qsub -Wdepend=afterany:2873 -- /bin/sleep 1000
2874.nimitz
[bmann@nimitz ~]$ qstat -f | grep depend
depend = beforeany:2874.nimitz@nimitz
depend = afterany:2873.nimitz@nimitz
...
[bmann@nimitz ~]$ qsub -- /bin/sleep 1000
2875.nimitz
[bmann@nimitz ~]$ qalter -Wdepend=afterany:2875 2874
[bmann@nimitz ~]$ qstat -f | grep depend
depend = beforeany:2874.nimitz@nimitz
depend = afterany:2875.nimitz@nimitz
...
depend = beforeany:2874.nimitz@nimitz
The afterany dependency is replaced by the qalter.
As a note, the beforeany dependency on the first job is not released when the initial afterany dependency is.
Now if I do what you suggest with different types of dependencies, I get the suggested behavior
[bmann@nimitz ~]$ qsub -- /bin/sleep 1000
2879.nimitz
[bmann@nimitz ~]$ qsub -Wdepend=afterany:2879 -- /bin/sleep 1000
2880.nimitz
[bmann@nimitz ~]$ qstat -f | grep depend
depend = beforeany:2880.nimitz@nimitz
depend = afterany:2879.nimitz@nimitz
...
[bmann@nimitz ~]$ qsub -- /bin/sleep 1000
2881.nimitz
[bmann@nimitz ~]$ qalter -Wdepend=afterok:2881 2880
[bmann@nimitz ~]$ qstat -f | grep depend
depend = beforeany:2880.nimitz@nimitz
depend = afterany:2879.nimitz@nimitz,afterok:2881.nimitz@nimitz
...
depend = beforeok:2880.nimitz@nimitz
Note, I removed Submit_Arguments from the qstats to avoid confusion.
I think the correct behavior is to be consistent over all cases. Since multiple qalters replace the dependencies, I think no combination of qsub/qalter should add them.
Bhroam
I updated the design document a little. There is one function that handles building the ‘S’ and ‘E’ records. I reused it to build the ‘Q’ record and kept all the data we had at the time. I added the new fields to the ‘Q’ record in the document.
Also, only when a server hook modifies a job will an ‘a’ record be printed. The mom hooks have very few things they can modify. It turned out to be pretty much impossible to print them anyway. The mom sends a stat update back to the server with several attributes it updates (e.g., session_id), and the attributes modified by hooks are intermixed. It would be impossible to determine if a mom hook modified an attribute or the mom itself. There’s also the fact that we don’t want resources_used to get an ‘a’ record at all. We only want that showing up in the ‘E’ record.
Now that I’ve implemented the code, I updated the examples.
Hey @bhroam, sorry that I hadn’t noticed this before, but I think that we should only be printing 1 ‘a’ record which lists all attributes altered at a time instead of n ‘a’ records for the n attributes modified.
So, for “qalter -lmin_walltime=1:00 -l max_walltime=1:00:00 1009”, I think that we should print only 1 ‘a’ record:
10/22/2019 12:22:57;a;1009.mars;Resource_List.min_walltime=00:01:00 Resource_List.max_walltime=01:00:00
instead of 2:
10/22/2019 12:22:57;a;1009.mars;Resource_List.min_walltime=00:01:00
10/22/2019 12:22:57;a;1009.mars;Resource_List.max_walltime=01:00:00
What do you think?
I agree with Ravi here, I do not see any added benefit of having one record for each attribute that changes.
I look at it from the other way. I don’t want a difference between doing two qalters and doing one. I want the log to look the same.
@scc do you have an opinion on the matter?
Bhroam
No strong opinion. Until the latest example update I had assumed there would be 1 log entry per qalter, not 1 entry per attribute altered. Ultimately, I am not sure it makes much difference either way to whatever ends up consuming the data as long as the data is there. I’d slightly favor 1 entry per qalter simply because it is less verbose and conveys the same information.
Come to think of it, hooks might throw a hitch into this. For modifyjob hooks, it is easy enough to combine all the alters onto the same line along with the attributes modified with qalter. The same is not the same for runjob hooks. There is a function that is called to set a single attribute and a different attribute which is called to set resources. It’s not easy without changing how attributes and resources are set in runjob hooks to print them all one one line.
I don’t want different behavior for different types of hooks.
I seem to be in the minority on how to print this, so what do you guys think?
Bhroam
I actually imagined this record to be more transactional in nature. I understand that with current code it is not possible to combine alters of multiple attributes in one line for some hooks.
But, I find it a little odd that if a user issues a qalter command and modifies 3 different attributes of a job, we will end up logging 3 different alter records.
Since the accounting log is an interface that we expose to the external world, I don’t think that we should set this expectation for people who are writing parsers that they expect only one key-value pair in each ‘alter’ record. We should rather keep interface open for us to log more than one attribute in each ‘alter’ record.
I had a conversation with @billnitzberg and he had a very good point. The accounting log still prints in the granularity of seconds. If I were to print the ‘a’ records one per line, there is a chance it might move from one second to the next while printing records for one qalter. It would then make it look like the qalters were done differently.
I’ve made the modifications to the design document and the code.
Bhroam