Unsolved
This post is more than 5 years old
6 Operator
•
14.4K Posts
•
56.2K Points
0
782
February 1st, 2013 15:00
My jobdb is bigger than yours...
Sorry for title... that was only to get some attention In our company we have several backup servers - it kind of mixed bag of toys which will take some time to harmonize, but I'm mostly attached to the one I built and maintain for past couple of years. It is HPUX based server which serves some 600 file system clients, few NDMP filers and some 300 databases (SQL, Oracle and SAP). My journey with current hardware started with 7.4.x and since I have jumped tp 7.5.3.5, then 7.6.3.6, then 7.6.4.2 and most recently 7.6.5.0. Anyway, to cut the story, with each release I would see jobdb going more and more wild in terms of CPU usage. (yes, yes, I know legendary stories about jobdb in nw8 - I can't go there yet)
I believe first hit which jobdb might have got was browsing sessions caused by NMDA, but I could be wrong. If wrong, there is beautiful coincidence. However, it was not that bad. I didn't have any operational issues except looking at the CPU stats made wonder why, oh why. Then, couple of months ago we switched from EDL to Data Domain. Initially I was playing with VTL and that worked ok. Target of course was DD device so I went to it too. This initially worked very nice, it does now too, but I also noticed two things (at this point, I was running 7.6.4.2):
a) nsrjobdb is more agressive
b) nsrmmdbd is more being used
Once thing, which I could observe but never really catch in act, was the point where certain Oracle archive logs would fail with connection timed out messages. This was random and not so frequent so I was not bothered too much (I run those every 1h). However, I also noticed that I was getting more and more issues where sessions would get queued and nothing would help - they would never get initiated (savefs) on client at all. Time frame was specific and indicated I might have more than server was capable to run at that time though all server stats (OS) showed that server can do whatever it wants in parallel. During 7.6.4.2 era, I did debug savegrp once to see what is going on, but nothing much apparently:
Received job state change message
client.domain:client.domain:Probe (216277) Received job state change message from UNKNOWN to CREATED
client.domain:client.domain:Probe (216277) Processing job state change from CREATED to CREATED
sg_pick_next_job(): Entry...
Received job state change message
client.domain:client.domain:Probe (216277) Received job state change message from CREATED to QUEUED
client.domain:client.domain:Probe (216277) Processing job state change from CREATED to QUEUED
sg_pick_next_job(): Entry...
lg_open(): Calling open64().
4690:savegrp: Group GROUP_NAME waiting for 1 jobs to complete
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
[endless...]
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
sg_pick_next_job(): Entry...
76658:savegrp: group GROUP_NAME is being aborted. Reason: Hardlimit
Aborting job 216277, timeout 120, reason 'Hardlimit'
Received job state change message
client.domain:client.domain:Probe (216277) Received job state change message from QUEUED to COMPLETED
client.domain:client.domain:Probe (216277) Processing job state change from QUEUED to COMPLETED
process_job_end(): job (216277) completed
process_job_completion(): Job client.domain:client.domain:Probe with id 216277 has completed.
generate_job_completion_status(): Generating job completion status for job 216277.
7336:savegrp: Log file /nsr/tmp/sg/GROUP_NAME/sso.client.domain.000002 is empty.
77568:savegrp: GROUP_NAME * client.domain:Probe Cannot determine status of probe process. The log file is empty.
7341:savegrp: client.domain:Probe unexpectedly exited.
Updating completion status for job 216277
lg_open(): Calling open64().
process_job_completion(): Quit flag has been set for group GROUP_NAME.
32490:savegrp: group GROUP_NAME aborted.
gossip_about_totals(): enter.
gossip_about_totals: Calling update_groupstat.
update_groupstat: enter.
update_groupstat: client_status failed.
update_groupstat: group failed.
update_groupstat: sg_exit_code = 1
resizing report_buffer: ptr=0000000000000000, size=32769
add_message_to_report(): message 'GROUP_NAME aborted, Total 1 client(s), 1 Failed. Please see group completion details for more information.
As you can see, after 120 minutes, job was killed - for 120 minutes, I could not see on client savefs job being run. For 120 minutes, this thing didn't even created a session to client. And before you ask, there is no firewall, there is no network problem. But there is a pattern.
Endless fire fighting shows that if I disable all SQL and ORA archive/transaction log groups, after couple of hours server will get back to senses and everything queued will kick in. The only reason why I did this for SQL and ORA is simply because these groups run every 1h so I just wanted to lower the pressure of many groups trying to start every so often. So, or at least I believed so, I had sort of workaround though it was outside working hours. One thing I noticed too was that after restart things would be perfect for at least two days - no issues with spawning sessions, no time outs - perfect life actually. Since I plan to start testing nw8 and jump to it somewhere later this year (not before early or late summer), I went for SP5 last weekend. After two days I started to get bunch of problems and suddenly no session would be spawned - in logs/nsrwatch you could nothing running. This caused incident as one production archive log destination filled so my morning didn't start with smile. Restart, all ok. Actually perfect. I started all groups which were killed at the same time to see if I can drive this thing crazy - nope, it just worked perfect. This morning I noticed that time outs started to kick again and almost with every group had at least one job which was shown as timed out. And there is one important thing I forgot when it comes to earlier mentioned incident, during that phase we noticed that client initiated archive log jobs worked just fine. So, issue was server side for sure. Wether OS or NW was open for debate. Anyway, by the time I came home, server did get frozen again (perhaps frozen is not right word because it is very responsive to nsrwatch for sure), there was no session running at all and I had already "stale" some 60 groups. Before kill it, I did dbgcommand on nsrd since this is master, to nsrjobdb which was 99% even no JOB cleanup was running (easily verified via daemon.raw) and nsrmmdbd which was happily at 80%. Not only that, but in logs I could see that two remote nsrmmds had to be restarted too (once again, no network issue, this is pure NW). The fact that job daemon was not running cleanup, but it was still 99% did ring some alerts, but I still have to review daemon.raw which is some 200MB in size. And the fact that this happens every 2 days since SP5 was applied could be yet another beautiful coincidence, but conspiracy theory is more likely. Especially if you keep in mind the fact that every time I restart NW I also delete jobdb database. That might just explain periods of peace. And in case that you wonder if nsrim was running at that time - no, it was not.
So, I'm now almost convinced that issue I see is related to jobdb (which in SP5 compared to SP4 is - bad - if any of above reflects jobdb's fault). While trying to figure out what to do next, since I can't jump to NW8 due to many dependencies, two things crossed my mind, but I need someone's experience who went down that path before here:
- One thing, with which I could leave, is to delete all records in jobdb which are completed, but instead of jobdb doing it, I would do it. The problem is, jobquery can list jobs, but not files. And on top it, it does not have delete option from what I could see. So another idea popped out which is - disable all groups and while no group is running just delete content of jobdb, but preserve directory structure. Not sure if anyone has tried to do that before, but if it did I wonder how safe it is or what penalty might be there. I guess related question would be, is there a way how to control when cleaning takes place which now seems to be trigerred every 1 hour.
- One thing I just noticed is that jobdb configuration shows retention in hours. I'm almost 100% sure that it used to in days before, but with SP5 it says in hours (and it shows 72 hours where before my config was 1 day). Does anyone know what job inactivity timeout does and how it is designed to operate?
I assume, if I leave jobdb to group for 6 days and then do cleanup of Sunday it would make things easier for me, but this remains to be tested. Problem is I can't do cleanup using NW tools they was I want it. Anyone else been experimenting with this using 7.6.x?


ble1
6 Operator
•
14.4K Posts
•
56.2K Points
0
February 1st, 2013 15:00
The more I think about this, more I believe that "spontaneous" change of jobdb retention from 1 day to 72 hours is somewhat related to what I have seen as an escalation of my "old" problem. I changed it to 12 hours - wonder what effect I will see (probably I will need to bounce NW for that to take effect).
ble1
6 Operator
•
14.4K Posts
•
56.2K Points
0
February 3rd, 2013 13:00
To answer myself, nope, it takes effect without NW restart.