]> git.sur5r.net Git - bacula/bacula/blob - bacula/src/dird/jobq.c
Improve debug output scheduler+jobq+tracing
[bacula/bacula] / bacula / src / dird / jobq.c
1 /*
2  * Bacula job queue routines.
3  *
4  *  This code consists of three queues, the waiting_jobs
5  *  queue, where jobs are initially queued, the ready_jobs
6  *  queue, where jobs are placed when all the resources are
7  *  allocated and they can immediately be run, and the
8  *  running queue where jobs are placed when they are
9  *  running.
10  *
11  *  Kern Sibbald, July MMIII
12  *
13  *   Version $Id$
14  *
15  *  This code was adapted from the Bacula workq, which was
16  *    adapted from "Programming with POSIX Threads", by
17  *    David R. Butenhof
18  *
19  */
20 /*
21    Copyright (C) 2000-2003 Kern Sibbald and John Walker
22
23    This program is free software; you can redistribute it and/or
24    modify it under the terms of the GNU General Public License as
25    published by the Free Software Foundation; either version 2 of
26    the License, or (at your option) any later version.
27
28    This program is distributed in the hope that it will be useful,
29    but WITHOUT ANY WARRANTY; without even the implied warranty of
30    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
31    General Public License for more details.
32
33    You should have received a copy of the GNU General Public
34    License along with this program; if not, write to the Free
35    Software Foundation, Inc., 59 Temple Place - Suite 330, Boston,
36    MA 02111-1307, USA.
37
38  */
39
40 #include "bacula.h"
41 #include "dird.h"
42
43
44 /* Forward referenced functions */
45 static void *jobq_server(void *arg);
46 static int   start_server(jobq_t *jq);
47
48 /*   
49  * Initialize a job queue
50  *
51  *  Returns: 0 on success
52  *           errno on failure
53  */
54 int jobq_init(jobq_t *jq, int threads, void *(*engine)(void *arg))
55 {
56    int stat;
57    jobq_item_t *item = NULL;
58                         
59    if ((stat = pthread_attr_init(&jq->attr)) != 0) {
60       Jmsg1(NULL, M_ERROR, 0, "pthread_attr_init: ERR=%s\n", strerror(stat));
61       return stat;
62    }
63    if ((stat = pthread_attr_setdetachstate(&jq->attr, PTHREAD_CREATE_DETACHED)) != 0) {
64       pthread_attr_destroy(&jq->attr);
65       return stat;
66    }
67    if ((stat = pthread_mutex_init(&jq->mutex, NULL)) != 0) {
68       Jmsg1(NULL, M_ERROR, 0, "pthread_mutex_init: ERR=%s\n", strerror(stat));
69       pthread_attr_destroy(&jq->attr);
70       return stat;
71    }
72    if ((stat = pthread_cond_init(&jq->work, NULL)) != 0) {
73       Jmsg1(NULL, M_ERROR, 0, "pthread_cond_init: ERR=%s\n", strerror(stat));
74       pthread_mutex_destroy(&jq->mutex);
75       pthread_attr_destroy(&jq->attr);
76       return stat;
77    }
78    jq->quit = false;
79    jq->max_workers = threads;         /* max threads to create */
80    jq->num_workers = 0;               /* no threads yet */
81    jq->idle_workers = 0;              /* no idle threads */
82    jq->engine = engine;               /* routine to run */
83    jq->valid = JOBQ_VALID; 
84    /* Initialize the job queues */
85    jq->waiting_jobs = new dlist(item, &item->link);
86    jq->running_jobs = new dlist(item, &item->link);
87    jq->ready_jobs = new dlist(item, &item->link);
88    return 0;
89 }
90
91 /*
92  * Destroy the job queue
93  *
94  * Returns: 0 on success
95  *          errno on failure
96  */
97 int jobq_destroy(jobq_t *jq)
98 {
99    int stat, stat1, stat2;
100
101   if (jq->valid != JOBQ_VALID) {
102      return EINVAL;
103   }
104   if ((stat = pthread_mutex_lock(&jq->mutex)) != 0) {
105      Jmsg1(NULL, M_ERROR, 0, "pthread_mutex_lock: ERR=%s\n", strerror(stat));
106      return stat;
107   }
108   jq->valid = 0;                      /* prevent any more operations */
109
110   /* 
111    * If any threads are active, wake them 
112    */
113   if (jq->num_workers > 0) {
114      jq->quit = true;
115      if (jq->idle_workers) {
116         if ((stat = pthread_cond_broadcast(&jq->work)) != 0) {
117            Jmsg1(NULL, M_ERROR, 0, "pthread_cond_broadcast: ERR=%s\n", strerror(stat));
118            pthread_mutex_unlock(&jq->mutex);
119            return stat;
120         }
121      }
122      while (jq->num_workers > 0) {
123         if ((stat = pthread_cond_wait(&jq->work, &jq->mutex)) != 0) {
124            Jmsg1(NULL, M_ERROR, 0, "pthread_cond_wait: ERR=%s\n", strerror(stat));
125            pthread_mutex_unlock(&jq->mutex);
126            return stat;
127         }
128      }
129   }
130   if ((stat = pthread_mutex_unlock(&jq->mutex)) != 0) {
131      Jmsg1(NULL, M_ERROR, 0, "pthread_mutex_unlock: ERR=%s\n", strerror(stat));
132      return stat;
133   }
134   stat  = pthread_mutex_destroy(&jq->mutex);
135   stat1 = pthread_cond_destroy(&jq->work);
136   stat2 = pthread_attr_destroy(&jq->attr);
137   delete jq->waiting_jobs;
138   delete jq->running_jobs;
139   delete jq->ready_jobs;
140   return (stat != 0 ? stat : (stat1 != 0 ? stat1 : stat2));
141 }
142
143 struct wait_pkt {
144    JCR *jcr;
145    jobq_t *jq;
146 };
147
148 /*
149  * Wait until schedule time arrives before starting. Normally
150  *  this routine is only used for jobs started from the console
151  *  for which the user explicitly specified a start time. Otherwise
152  *  most jobs are put into the job queue only when their
153  *  scheduled time arives.
154  */
155 static void *sched_wait(void *arg)
156 {
157    JCR *jcr = ((wait_pkt *)arg)->jcr;
158    jobq_t *jq = ((wait_pkt *)arg)->jq;
159
160    Dmsg0(010, "Enter sched_wait.\n");
161    free(arg);
162    time_t wtime = jcr->sched_time - time(NULL);
163    /* Wait until scheduled time arrives */
164    if (wtime > 0 && verbose) {
165       Jmsg(jcr, M_INFO, 0, _("Job %s waiting %d seconds for scheduled start time.\n"), 
166          jcr->Job, wtime);
167       set_jcr_job_status(jcr, JS_WaitStartTime);
168    }
169    /* Check every 30 seconds if canceled */ 
170    while (wtime > 0) {
171       Dmsg2(010, "Waiting on sched time, jobid=%d secs=%d\n", jcr->JobId, wtime);
172       if (wtime > 30) {
173          wtime = 30;
174       }
175       bmicrosleep(wtime, 0);
176       if (job_canceled(jcr)) {
177          break;
178       }
179       wtime = jcr->sched_time - time(NULL);
180    }
181    P(jcr->mutex);                     /* lock jcr */
182    jobq_add(jq, jcr);
183    V(jcr->mutex);
184    free_jcr(jcr);                     /* we are done with jcr */
185    Dmsg0(010, "Exit sched_wait\n");
186    return NULL;
187 }
188
189
190 /*
191  *  Add a job to the queue
192  *    jq is a queue that was created with jobq_init
193  * 
194  *  On entry jcr->mutex must be locked.
195  *   
196  */
197 int jobq_add(jobq_t *jq, JCR *jcr)
198 {
199    int stat;
200    jobq_item_t *item, *li;
201    bool inserted = false;
202    time_t wtime = jcr->sched_time - time(NULL);
203    pthread_t id;
204    wait_pkt *sched_pkt;
205     
206    Dmsg3(000, "jobq_add jobid=%d jcr=0x%x use_count=%d\n", jcr->JobId, jcr, jcr->use_count);
207    if (jq->valid != JOBQ_VALID) {
208       Jmsg0(jcr, M_ERROR, 0, "Jobq_add queue not initialized.\n");
209       return EINVAL;
210    }
211
212    jcr->use_count++;                  /* mark jcr in use by us */
213
214    Dmsg3(010, "jobq_add jobid=%d jcr=0x%x use_count=%d\n", jcr->JobId, jcr, jcr->use_count);
215    if (!job_canceled(jcr) && wtime > 0) {
216       set_thread_concurrency(jq->max_workers + 2);
217       sched_pkt = (wait_pkt *)malloc(sizeof(wait_pkt));
218       sched_pkt->jcr = jcr;
219       sched_pkt->jq = jq;
220       stat = pthread_create(&id, &jq->attr, sched_wait, (void *)sched_pkt);        
221       if (stat != 0) {                /* thread not created */
222          Jmsg1(jcr, M_ERROR, 0, "pthread_thread_create: ERR=%s\n", strerror(stat));
223          jcr->use_count--;            /* release jcr */
224       }
225       return stat;
226    }
227
228    if ((stat = pthread_mutex_lock(&jq->mutex)) != 0) {
229       Jmsg1(jcr, M_ERROR, 0, "pthread_mutex_lock: ERR=%s\n", strerror(stat));
230       jcr->use_count--;               /* release jcr */
231       return stat;
232    }
233
234    if ((item = (jobq_item_t *)malloc(sizeof(jobq_item_t))) == NULL) {
235       jcr->use_count--;               /* release jcr */
236       return ENOMEM;
237    }
238    item->jcr = jcr;
239
240    if (job_canceled(jcr)) {
241       /* Add job to ready queue so that it is canceled quickly */
242       jq->ready_jobs->prepend(item);
243       Dmsg1(010, "Prepended job=%d to ready queue\n", jcr->JobId);
244    } else {
245       /* Add this job to the wait queue in priority sorted order */
246       foreach_dlist(li, jq->waiting_jobs) {
247          Dmsg2(010, "waiting item jobid=%d priority=%d\n",
248             li->jcr->JobId, li->jcr->JobPriority);
249          if (li->jcr->JobPriority > jcr->JobPriority) {
250             jq->waiting_jobs->insert_before(item, li);
251             Dmsg2(010, "insert_before jobid=%d before waiting job=%d\n", 
252                li->jcr->JobId, jcr->JobId);
253             inserted = true;
254             break;
255          }
256       }
257       /* If not jobs in wait queue, append it */
258       if (!inserted) {
259          jq->waiting_jobs->append(item);
260          Dmsg1(010, "Appended item jobid=%d to waiting queue\n", jcr->JobId);
261       }
262    }
263
264    /* Ensure that at least one server looks at the queue. */
265    stat = start_server(jq);
266
267    pthread_mutex_unlock(&jq->mutex);
268    Dmsg0(010, "Return jobq_add\n");
269    return stat;
270 }
271
272 /*
273  *  Remove a job from the job queue. Used only by cancel_job().
274  *    jq is a queue that was created with jobq_init
275  *    work_item is an element of work
276  *
277  *   Note, it is "removed" from the job queue.
278  *    If you want to cancel it, you need to provide some external means
279  *    of doing so (e.g. pthread_kill()).
280  */
281 int jobq_remove(jobq_t *jq, JCR *jcr)
282 {
283    int stat;
284    bool found = false;
285    jobq_item_t *item;
286     
287    Dmsg2(010, "jobq_remove jobid=%d jcr=0x%x\n", jcr->JobId, jcr);
288    if (jq->valid != JOBQ_VALID) {
289       return EINVAL;
290    }
291
292    if ((stat = pthread_mutex_lock(&jq->mutex)) != 0) {
293       Jmsg1(NULL, M_ERROR, 0, "pthread_mutex_lock: ERR=%s\n", strerror(stat));
294       return stat;
295    }
296
297    foreach_dlist(item, jq->waiting_jobs) {
298       if (jcr == item->jcr) {
299          found = true;
300          break;
301       }
302    }
303    if (!found) {
304       pthread_mutex_unlock(&jq->mutex);
305       Dmsg2(010, "jobq_remove jobid=%d jcr=0x%x not in wait queue\n", jcr->JobId, jcr);
306       return EINVAL;
307    }
308
309    /* Move item to be the first on the list */
310    jq->waiting_jobs->remove(item);
311    jq->ready_jobs->prepend(item);
312    Dmsg2(010, "jobq_remove jobid=%d jcr=0x%x moved to ready queue\n", jcr->JobId, jcr);
313    
314    stat = start_server(jq);
315
316    pthread_mutex_unlock(&jq->mutex);
317    Dmsg0(010, "Return jobq_remove\n");
318    return stat;
319 }
320
321
322 /*
323  * Start the server thread if it isn't already running
324  */
325 static int start_server(jobq_t *jq)
326 {
327    int stat = 0;
328    pthread_t id;
329
330    /* if any threads are idle, wake one */
331    if (jq->idle_workers > 0) {
332       Dmsg0(010, "Signal worker to wake up\n");
333       if ((stat = pthread_cond_signal(&jq->work)) != 0) {
334          Jmsg1(NULL, M_ERROR, 0, "pthread_cond_signal: ERR=%s\n", strerror(stat));
335          return stat;
336       }
337    } else if (jq->num_workers < jq->max_workers) {
338       Dmsg0(010, "Create worker thread\n");
339       /* No idle threads so create a new one */
340       set_thread_concurrency(jq->max_workers + 1);
341       if ((stat = pthread_create(&id, &jq->attr, jobq_server, (void *)jq)) != 0) {
342          Jmsg1(NULL, M_ERROR, 0, "pthread_create: ERR=%s\n", strerror(stat));
343          return stat;
344       }
345    }
346    return stat;
347 }
348
349
350 /* 
351  * This is the worker thread that serves the job queue.
352  * When all the resources are acquired for the job, 
353  *  it will call the user's engine.
354  */
355 static void *jobq_server(void *arg)
356 {
357    struct timespec timeout;
358    jobq_t *jq = (jobq_t *)arg;
359    jobq_item_t *je;                   /* job entry in queue */
360    int stat;
361    bool timedout;
362    bool work = true;
363
364    Dmsg0(010, "Start jobq_server\n");
365    if ((stat = pthread_mutex_lock(&jq->mutex)) != 0) {
366       Jmsg1(NULL, M_ERROR, 0, "pthread_mutex_lock: ERR=%s\n", strerror(stat));
367       return NULL;
368    }
369    jq->num_workers++;
370
371    for (;;) {
372       struct timeval tv;
373       struct timezone tz;
374
375       Dmsg0(010, "Top of for loop\n");
376       timedout = false;
377       gettimeofday(&tv, &tz);
378       timeout.tv_nsec = 0;
379       timeout.tv_sec = tv.tv_sec + 4;
380
381       while (!work && !jq->quit) {
382          /*
383           * Wait 4 seconds, then if no more work, exit
384           */
385          Dmsg0(010, "pthread_cond_timedwait()\n");
386          stat = pthread_cond_timedwait(&jq->work, &jq->mutex, &timeout);
387          if (stat == ETIMEDOUT) {
388             Dmsg0(010, "timedwait timedout.\n");
389             timedout = true;
390             break;
391          } else if (stat != 0) {
392             /* This shouldn't happen */
393             Dmsg0(010, "This shouldn't happen\n");
394             jq->num_workers--;
395             pthread_mutex_unlock(&jq->mutex);
396             return NULL;
397          }
398          break;
399       } 
400       /* 
401        * If anything is in the ready queue, run it
402        */
403       Dmsg0(010, "Checking ready queue.\n");
404       while (!jq->ready_jobs->empty() && !jq->quit) {
405          JCR *jcr;
406          je = (jobq_item_t *)jq->ready_jobs->first(); 
407          jcr = je->jcr;
408          jq->ready_jobs->remove(je);
409          if (!jq->ready_jobs->empty()) {
410             Dmsg0(010, "ready queue not empty start server\n");
411             if (start_server(jq) != 0) {
412                jq->num_workers--;
413                pthread_mutex_unlock(&jq->mutex);
414                return NULL;
415             }
416          }
417          jq->running_jobs->append(je);
418          Dmsg1(010, "Took jobid=%d from ready and appended to run\n", jcr->JobId);
419          if ((stat = pthread_mutex_unlock(&jq->mutex)) != 0) {
420             Jmsg1(NULL, M_ERROR, 0, "pthread_mutex_unlock: ERR=%s\n", strerror(stat));
421             jq->num_workers--;
422             return NULL;
423          }
424          /* Call user's routine here */
425          Dmsg1(010, "Calling user engine for jobid=%d\n", jcr->JobId);
426          jq->engine(je->jcr);
427          Dmsg1(010, "Back from user engine jobid=%d.\n", jcr->JobId);
428          if ((stat = pthread_mutex_lock(&jq->mutex)) != 0) {
429             Jmsg1(NULL, M_ERROR, 0, "pthread_mutex_unlock: ERR=%s\n", strerror(stat));
430             jq->num_workers--;
431             free(je);                 /* release job entry */
432             return NULL;
433          }
434          Dmsg0(200, "Done lock mutex after running job. Release locks.\n");
435          jq->running_jobs->remove(je);
436          /* 
437           * Release locks if acquired. Note, they will not have
438           *  been acquired for jobs canceled before they were
439           *  put into the ready queue.
440           */
441          if (jcr->acquired_resource_locks) {
442             jcr->store->NumConcurrentJobs--;
443             jcr->client->NumConcurrentJobs--;
444             jcr->job->NumConcurrentJobs--;
445          }
446
447          if (jcr->job->RescheduleOnError && 
448              jcr->JobStatus != JS_Terminated &&
449              jcr->JobStatus != JS_Canceled && 
450              jcr->job->RescheduleTimes > 0 && 
451              jcr->reschedule_count < jcr->job->RescheduleTimes) {
452
453              /*
454               * Reschedule this job by cleaning it up, but
455               *  reuse the same JobId if possible.
456               */
457             jcr->reschedule_count++;
458             jcr->sched_time = time(NULL) + jcr->job->RescheduleInterval;
459             Dmsg2(010, "Rescheduled Job %s to re-run in %d seconds.\n", jcr->Job,
460                (int)jcr->job->RescheduleInterval);
461             jcr->JobStatus = JS_Created; /* force new status */
462             dird_free_jcr(jcr);          /* partial cleanup old stuff */
463             if (jcr->JobBytes == 0) {
464                Dmsg1(010, "Requeue job=%d\n", jcr->JobId);
465                V(jq->mutex);
466                jobq_add(jq, jcr);     /* queue the job to run again */
467                P(jq->mutex);
468                free(je);              /* free the job entry */
469                continue;              /* look for another job to run */
470             }
471             /* 
472              * Something was actually backed up, so we cannot reuse
473              *   the old JobId or there will be database record
474              *   conflicts.  We now create a new job, copying the
475              *   appropriate fields.
476              */
477             JCR *njcr = new_jcr(sizeof(JCR), dird_free_jcr);
478             set_jcr_defaults(njcr, jcr->job);
479             njcr->reschedule_count = jcr->reschedule_count;
480             njcr->JobLevel = jcr->JobLevel;
481             njcr->JobStatus = jcr->JobStatus;
482             njcr->pool = jcr->pool;
483             njcr->store = jcr->store;
484             njcr->messages = jcr->messages;
485             Dmsg0(010, "Call to run new job\n");
486             V(jq->mutex);
487             run_job(njcr);            /* This creates a "new" job */
488             free_jcr(njcr);           /* release "new" jcr */
489             P(jq->mutex);
490             Dmsg0(010, "Back from running new job.\n");
491          }
492          /* Clean up and release old jcr */
493          if (jcr->db) {
494             db_close_database(jcr, jcr->db);
495             jcr->db = NULL;
496          }
497          Dmsg1(010, "====== Termination job=%d\n", jcr->JobId);
498          free_jcr(jcr);
499          free(je);                    /* release job entry */
500       }
501       /*
502        * If any job in the wait queue can be run,
503        *  move it to the ready queue
504        */
505       Dmsg0(010, "Done check ready, now check wait queue.\n");
506       while (!jq->waiting_jobs->empty() && !jq->quit) {
507          int Priority;
508          je = (jobq_item_t *)jq->waiting_jobs->first(); 
509          jobq_item_t *re = (jobq_item_t *)jq->running_jobs->first();
510          if (re) {
511             Priority = re->jcr->JobPriority;
512             Dmsg2(010, "JobId %d is running. Set pri=%d\n", re->jcr->JobId, Priority);
513          } else {
514             Priority = je->jcr->JobPriority;
515             Dmsg1(010, "No job running. Set Job pri=%d\n", Priority);
516          }
517          /*
518           * Walk down the list of waiting jobs and attempt
519           *   to acquire the resources it needs.
520           */
521          for ( ; je;  ) {
522             /* je is current job item on the queue, jn is the next one */
523             JCR *jcr = je->jcr;
524             jobq_item_t *jn = (jobq_item_t *)jq->waiting_jobs->next(je);
525             Dmsg3(010, "Examining Job=%d JobPri=%d want Pri=%d\n",
526                jcr->JobId, jcr->JobPriority, Priority);
527             /* Take only jobs of correct Priority */
528             if (jcr->JobPriority != Priority) {
529                set_jcr_job_status(jcr, JS_WaitPriority);
530                break;
531             }
532             if (jcr->store->NumConcurrentJobs < jcr->store->MaxConcurrentJobs) {
533                jcr->store->NumConcurrentJobs++;
534             } else {
535                set_jcr_job_status(jcr, JS_WaitStoreRes);
536                je = jn;
537                continue;
538             }
539             if (jcr->client->NumConcurrentJobs < jcr->client->MaxConcurrentJobs) {
540                jcr->client->NumConcurrentJobs++;
541             } else {
542                jcr->store->NumConcurrentJobs--;
543                set_jcr_job_status(jcr, JS_WaitClientRes);
544                je = jn;
545                continue;
546             }
547             if (jcr->job->NumConcurrentJobs < jcr->job->MaxConcurrentJobs) {
548                jcr->job->NumConcurrentJobs++;
549             } else {
550                jcr->store->NumConcurrentJobs--;
551                jcr->client->NumConcurrentJobs--;
552                set_jcr_job_status(jcr, JS_WaitJobRes);
553                je = jn;
554                continue;
555             }
556             /* Got all locks, now remove it from wait queue and append it
557              *   to the ready queue  
558              */
559             jcr->acquired_resource_locks = true;
560             jq->waiting_jobs->remove(je);
561             jq->ready_jobs->append(je);
562             Dmsg1(010, "moved JobId=%d from wait to ready queue\n", je->jcr->JobId);
563             je = jn;
564          } /* end for loop */
565          break;
566       } /* end while loop */
567       Dmsg0(010, "Done checking wait queue.\n");
568       /*
569        * If no more ready work and we are asked to quit, then do it
570        */
571       if (jq->ready_jobs->empty() && jq->quit) {
572          jq->num_workers--;
573          if (jq->num_workers == 0) {
574             Dmsg0(010, "Wake up destroy routine\n");
575             /* Wake up destroy routine if he is waiting */
576             pthread_cond_broadcast(&jq->work);
577          }
578          break;
579       }
580       Dmsg0(010, "Check for work request\n");
581       /* 
582        * If no more work requests, and we waited long enough, quit
583        */
584       Dmsg2(010, "timedout=%d read empty=%d\n", timedout,
585          jq->ready_jobs->empty());
586       if (jq->ready_jobs->empty() && timedout) {
587          Dmsg0(010, "break big loop\n");
588          jq->num_workers--;
589          break;
590       }
591       work = !jq->ready_jobs->empty() || !jq->waiting_jobs->empty();               
592       Dmsg1(010, "Loop again. work=%d\n", work);
593    } /* end of big for loop */
594
595    Dmsg0(200, "unlock mutex\n");
596    pthread_mutex_unlock(&jq->mutex);
597    Dmsg0(010, "End jobq_server\n");
598    return NULL;
599 }