From 2f53303a72bf843d200d3794277b0cc2bcb7de6d Mon Sep 17 00:00:00 2001 From: Kern Sibbald Date: Sun, 30 Sep 2007 17:19:20 +0000 Subject: [PATCH] kes Save jcr in thread specific data (tsd) for each thread. kes Make Dmsg() print JobId as -%u. kes Make Jmsg, Emsg, and others automatically pickup the jobid for the thread if it exists. kes Remove old reservation debug jid code. kes Remove get_jcr_from_tid() from OpenSSL and tls code. ebl Add an option that permit to specify spool size in job definition. (Applying patches/testing/spoolsize_per_job.patch). You must upgrade SD and DIR at the same time. git-svn-id: https://bacula.svn.sourceforge.net/svnroot/bacula/trunk@5696 91ce42f0-d328-0410-95d8-f526ca767f89 --- bacula/patches/2.2.4-lost-block.patch | 30 ++ bacula/patches/2.2.4-parse-command.patch | 28 ++ bacula/patches/2.2.4-restore.patch | 49 +++ bacula/patches/2.2.4-sql.patch | 476 +++++++++++++++++++++++ bacula/src/dird/job.c | 3 +- bacula/src/dird/jobq.c | 39 +- bacula/src/dird/msgchan.c | 1 + bacula/src/lib/crypto.c | 16 +- bacula/src/lib/jcr.c | 89 +++-- bacula/src/lib/message.c | 45 ++- bacula/src/lib/openssl.c | 13 +- bacula/src/lib/protos.h | 7 +- bacula/src/lib/tls.c | 14 +- bacula/src/stored/dev.c | 2 +- bacula/src/stored/reserve.c | 268 ++++++------- bacula/technotes-2.3 | 30 +- 16 files changed, 845 insertions(+), 265 deletions(-) create mode 100644 bacula/patches/2.2.4-lost-block.patch create mode 100644 bacula/patches/2.2.4-parse-command.patch create mode 100644 bacula/patches/2.2.4-restore.patch create mode 100644 bacula/patches/2.2.4-sql.patch diff --git a/bacula/patches/2.2.4-lost-block.patch b/bacula/patches/2.2.4-lost-block.patch new file mode 100644 index 0000000000..fbf7122a31 --- /dev/null +++ b/bacula/patches/2.2.4-lost-block.patch @@ -0,0 +1,30 @@ + + This patch fixes a race condition where a Job is terminating at the same + time that another job reaches the end of Volume. In that case, sometimes + the last block or two are not written to the Volume. This seems to be + relatively rare, but does result in data loss. This fixes bug #964. + + Apply the patch to Bacula version 2.2.4 (or possibly any previous 2.2.x + version) with: + + cd + patch -p0 <2.2.4-lost-block.patch + ./configure (your options) + make + ... + make install + + +Index: src/stored/append.c +=================================================================== +--- src/stored/append.c (revision 5602) ++++ src/stored/append.c (working copy) +@@ -287,7 +287,7 @@ + * Check if we can still write. This may not be the case + * if we are at the end of the tape or we got a fatal I/O error. + */ +- if (dev->can_write()) { ++ if (ok || dev->can_write()) { + if (!write_session_label(dcr, EOS_LABEL)) { + Jmsg1(jcr, M_FATAL, 0, _("Error writting end session label. ERR=%s\n"), + dev->bstrerror()); diff --git a/bacula/patches/2.2.4-parse-command.patch b/bacula/patches/2.2.4-parse-command.patch new file mode 100644 index 0000000000..312dd29efe --- /dev/null +++ b/bacula/patches/2.2.4-parse-command.patch @@ -0,0 +1,28 @@ + + This patch resolves a command parser issue + causing a director segfault when using something + like "run job 1 2" + + Apply to version 2.2.4 (and perhaps older 2.2.x versions) with + + cd + patch -p0 <2.2.4-parse-command.patch + ./configure (your options) + make + ... + make install + + +Index: src/dird/ua_run.c +=================================================================== +--- src/dird/ua_run.c (révision 5616) ++++ src/dird/ua_run.c (copie de travail) +@@ -933,7 +933,7 @@ + /* Note, yes and run have no value, so do not fail */ + if (!ua->argv[i] && j != YES_POS /*yes*/) { + ua->send_msg(_("Value missing for keyword %s\n"), ua->argk[i]); +- return true; ++ return false; + } + Dmsg1(800, "Got keyword=%s\n", NPRT(kw[j])); + switch (j) { diff --git a/bacula/patches/2.2.4-restore.patch b/bacula/patches/2.2.4-restore.patch new file mode 100644 index 0000000000..3ef991e3b7 --- /dev/null +++ b/bacula/patches/2.2.4-restore.patch @@ -0,0 +1,49 @@ + + This patch resolves bug #955 where the director segfault when + where= option isn't specified anywhere. + + Apply to version 2.2.4 (and perhaps older 2.2.x versions) with + + cd + patch -p0 <2.2.4-restore.patch + ./configure (your options) + make + ... + make install + + +Index: src/dird/restore.c +=================================================================== +--- src/dird/restore.c (revision 5601) ++++ src/dird/restore.c (working copy) +@@ -173,7 +173,7 @@ + } + + /* Send restore command */ +- char replace, *where, *cmd=NULL; ++ char replace, *where, *cmd; + char empty = '\0'; + + if (jcr->replace != 0) { +@@ -183,8 +183,6 @@ + } else { + replace = REPLACE_ALWAYS; /* always replace */ + } +- +- where = ∅ /* default */ + + if (jcr->RegexWhere) { + where = jcr->RegexWhere; /* override */ +@@ -199,7 +197,11 @@ + } else if (jcr->job->RestoreWhere) { + where = jcr->job->RestoreWhere; /* no override take from job */ + cmd = restorecmd; +- } ++ ++ } else { /* nothing was specified */ ++ where = ∅ /* use default */ ++ cmd = restorecmd; ++ } + + jcr->prefix_links = jcr->job->PrefixLinks; + diff --git a/bacula/patches/2.2.4-sql.patch b/bacula/patches/2.2.4-sql.patch new file mode 100644 index 0000000000..24de09994c --- /dev/null +++ b/bacula/patches/2.2.4-sql.patch @@ -0,0 +1,476 @@ + + This patch fixes several problems: it fixes incorrect or incomplete error + messages; it fixes a problem opening the SQLite3 database when multiple + simultaneous jobs were running; it fixes a bug with certain versions of + MySQL where batch inserts failed because of table name character case + (upper/lower) differences. + + It can be applied to version 2.2.4 (and possibly earlier 2.2.x versions) + with: + + cd + patch -p0 <2.2.4-sql.patch + ./configure (your options) + make + ... + make install + + + +Index: src/cats/sql.c +=================================================================== +--- src/cats/sql.c (revision 5687) ++++ src/cats/sql.c (working copy) +@@ -115,7 +115,6 @@ + + bacula_db_version = 0; + if (!db_sql_query(mdb, query, int_handler, (void *)&bacula_db_version)) { +- Mmsg(mdb->errmsg, "Database not created or server not running.\n"); + Jmsg(jcr, M_FATAL, 0, "%s", mdb->errmsg); + return false; + } +Index: src/cats/sqlite.c +=================================================================== +--- src/cats/sqlite.c (revision 5687) ++++ src/cats/sqlite.c (working copy) +@@ -148,6 +148,7 @@ + int len; + struct stat statbuf; + int errstat; ++ int retry = 0; + + P(mutex); + if (mdb->connected) { +@@ -157,8 +158,9 @@ + mdb->connected = FALSE; + + if ((errstat=rwl_init(&mdb->lock)) != 0) { ++ berrno be; + Mmsg1(&mdb->errmsg, _("Unable to initialize DB lock. ERR=%s\n"), +- strerror(errstat)); ++ be.bstrerror(errstat)); + V(mutex); + return 0; + } +@@ -178,28 +180,28 @@ + return 0; + } + ++ for (mdb->db=NULL; !mdb->db && retry++ < 10; ) { + #ifdef HAVE_SQLITE3 +- int stat = sqlite3_open(db_name, &mdb->db); +- if (stat != SQLITE_OK) { +- mdb->sqlite_errmsg = (char *)sqlite3_errmsg(mdb->db); +- sqlite3_close(mdb->db); +- mdb->db = NULL; +- } else { +- mdb->sqlite_errmsg = NULL; +- } +-#ifdef SQLITE3_INIT_QUERY +- db_sql_query(mdb, SQLITE3_INIT_QUERY, NULL, NULL); +-#endif +- ++ int stat = sqlite3_open(db_name, &mdb->db); ++ if (stat != SQLITE_OK) { ++ mdb->sqlite_errmsg = (char *)sqlite3_errmsg(mdb->db); ++ sqlite3_close(mdb->db); ++ mdb->db = NULL; ++ } else { ++ mdb->sqlite_errmsg = NULL; ++ } + #else +- mdb->db = sqlite_open( +- db_name, /* database name */ +- 644, /* mode */ +- &mdb->sqlite_errmsg); /* error message */ ++ mdb->db = sqlite_open( ++ db_name, /* database name */ ++ 644, /* mode */ ++ &mdb->sqlite_errmsg); /* error message */ + #endif + +- Dmsg0(300, "sqlite_open\n"); +- ++ Dmsg0(300, "sqlite_open\n"); ++ if (!mdb->db) { ++ bmicrosleep(1, 0); ++ } ++ } + if (mdb->db == NULL) { + Mmsg2(&mdb->errmsg, _("Unable to open Database=%s. ERR=%s\n"), + db_name, mdb->sqlite_errmsg ? mdb->sqlite_errmsg : _("unknown")); +@@ -209,10 +211,6 @@ + } + mdb->connected = true; + free(db_name); +- if (!check_tables_version(jcr, mdb)) { +- V(mutex); +- return 0; +- } + + /* set busy handler to wait when we use mult_db_connections = 1 */ + #ifdef HAVE_SQLITE3 +@@ -221,6 +219,16 @@ + sqlite_busy_handler(mdb->db, my_busy_handler, NULL); + #endif + ++#if defined(HAVE_SQLITE3) && defined(SQLITE3_INIT_QUERY) ++ db_sql_query(mdb, SQLITE3_INIT_QUERY, NULL, NULL); ++#endif ++ ++ if (!check_tables_version(jcr, mdb)) { ++ V(mutex); ++ return 0; ++ } ++ ++ + V(mutex); + return 1; + } +@@ -448,16 +456,20 @@ + return mdb->fields[mdb->field++]; + } + +-char *my_sqlite_batch_lock_query = "BEGIN"; +-char *my_sqlite_batch_unlock_query = "COMMIT"; +-char *my_sqlite_batch_fill_path_query = "INSERT INTO Path (Path) " +- " SELECT DISTINCT Path FROM batch " +- " EXCEPT SELECT Path FROM Path "; ++#ifdef HAVE_BATCH_FILE_INSERT ++const char *my_sqlite_batch_lock_query = "BEGIN"; ++const char *my_sqlite_batch_unlock_query = "COMMIT"; + +-char *my_sqlite_batch_fill_filename_query = "INSERT INTO Filename (Name) " +- " SELECT DISTINCT Name FROM batch " +- " EXCEPT SELECT Name FROM Filename "; ++const char *my_sqlite_batch_fill_path_query = ++ "INSERT INTO Path (Path)" ++ " SELECT DISTINCT Path FROM batch" ++ " EXCEPT SELECT Path FROM Path"; + ++const char *my_sqlite_batch_fill_filename_query = ++ "INSERT INTO Filename (Name)" ++ " SELECT DISTINCT Name FROM batch " ++ " EXCEPT SELECT Name FROM Filename"; ++#endif /* HAVE_BATCH_FILE_INSERT */ + + + #endif /* HAVE_SQLITE */ +Index: src/cats/cats.h +=================================================================== +--- src/cats/cats.h (revision 5687) ++++ src/cats/cats.h (working copy) +@@ -187,10 +187,10 @@ + int my_sqlite_query(B_DB *mdb, const char *cmd); + void my_sqlite_field_seek(B_DB *mdb, int field); + SQL_FIELD *my_sqlite_fetch_field(B_DB *mdb); +-extern char* my_sqlite_batch_lock_query; +-extern char* my_sqlite_batch_unlock_query; +-extern char* my_sqlite_batch_fill_filename_query; +-extern char* my_sqlite_batch_fill_path_query; ++extern const char* my_sqlite_batch_lock_query; ++extern const char* my_sqlite_batch_unlock_query; ++extern const char* my_sqlite_batch_fill_filename_query; ++extern const char* my_sqlite_batch_fill_path_query; + + + #else +@@ -317,10 +317,10 @@ + int my_sqlite_query(B_DB *mdb, const char *cmd); + void my_sqlite_field_seek(B_DB *mdb, int field); + SQL_FIELD *my_sqlite_fetch_field(B_DB *mdb); +-extern char* my_sqlite_batch_lock_query; +-extern char* my_sqlite_batch_unlock_query; +-extern char* my_sqlite_batch_fill_filename_query; +-extern char* my_sqlite_batch_fill_path_query; ++extern const char* my_sqlite_batch_lock_query; ++extern const char* my_sqlite_batch_unlock_query; ++extern const char* my_sqlite_batch_fill_filename_query; ++extern const char* my_sqlite_batch_fill_path_query; + + + #else +@@ -398,11 +398,11 @@ + #define sql_batch_fill_path_query my_mysql_batch_fill_path_query + + +-extern char* my_mysql_batch_lock_path_query; +-extern char* my_mysql_batch_lock_filename_query; +-extern char* my_mysql_batch_unlock_tables_query; +-extern char* my_mysql_batch_fill_filename_query; +-extern char* my_mysql_batch_fill_path_query; ++extern const char* my_mysql_batch_lock_path_query; ++extern const char* my_mysql_batch_lock_filename_query; ++extern const char* my_mysql_batch_unlock_tables_query; ++extern const char* my_mysql_batch_fill_filename_query; ++extern const char* my_mysql_batch_fill_path_query; + extern void my_mysql_free_result(B_DB *mdb); + + #else +@@ -486,11 +486,11 @@ + int my_postgresql_batch_insert(JCR *jcr, B_DB *mdb, ATTR_DBR *ar); + char *my_postgresql_copy_escape(char *dest, char *src, size_t len); + +-extern char* my_pg_batch_lock_path_query; +-extern char* my_pg_batch_lock_filename_query; +-extern char* my_pg_batch_unlock_tables_query; +-extern char* my_pg_batch_fill_filename_query; +-extern char* my_pg_batch_fill_path_query; ++extern const char* my_pg_batch_lock_path_query; ++extern const char* my_pg_batch_lock_filename_query; ++extern const char* my_pg_batch_unlock_tables_query; ++extern const char* my_pg_batch_fill_filename_query; ++extern const char* my_pg_batch_fill_path_query; + + /* "Generic" names for easier conversion */ + #define sql_store_result(x) ((x)->result) +Index: src/cats/mysql.c +=================================================================== +--- src/cats/mysql.c (revision 5687) ++++ src/cats/mysql.c (working copy) +@@ -149,8 +149,9 @@ + } + + if ((errstat=rwl_init(&mdb->lock)) != 0) { ++ berrno be; + Mmsg1(&mdb->errmsg, _("Unable to initialize DB lock. ERR=%s\n"), +- strerror(errstat)); ++ be.bstrerror(errstat)); + V(mutex); + return 0; + } +@@ -403,33 +404,27 @@ + db_unlock(mdb); + } + +-char *my_mysql_batch_lock_path_query = "LOCK TABLES Path write, " +- " batch write, " +- " Path as p write "; ++#ifdef HAVE_BATCH_FILE_INSERT ++const char *my_mysql_batch_lock_path_query = ++ "LOCK TABLES Path write, batch write, Path as p write"; + + +-char *my_mysql_batch_lock_filename_query = "LOCK TABLES Filename write, " +- " batch write, " +- " Filename as f write "; ++const char *my_mysql_batch_lock_filename_query = ++ "LOCK TABLES Filename write, batch write, Filename as f write"; + +-char *my_mysql_batch_unlock_tables_query = "UNLOCK TABLES"; ++const char *my_mysql_batch_unlock_tables_query = "UNLOCK TABLES"; + +-char *my_mysql_batch_fill_path_query = "INSERT INTO Path (Path) " +- " SELECT a.Path FROM " +- " (SELECT DISTINCT Path " +- " FROM batch) AS a " +- " WHERE NOT EXISTS " +- " (SELECT Path " +- " FROM Path AS p " +- " WHERE p.Path = a.Path) "; ++const char *my_mysql_batch_fill_path_query = ++ "INSERT INTO Path (Path) " ++ "SELECT a.Path FROM " ++ "(SELECT DISTINCT Path FROM batch) AS a WHERE NOT EXISTS " ++ "(SELECT Path FROM Path AS p WHERE p.Path = a.Path)"; + +-char *my_mysql_batch_fill_filename_query = "INSERT INTO Filename (Name) " +- " SELECT a.Name FROM " +- " (SELECT DISTINCT Name " +- " FROM batch) AS a " +- " WHERE NOT EXISTS " +- " (SELECT Name " +- " FROM Filename AS f " +- " WHERE f.Name = a.Name) "; ++const char *my_mysql_batch_fill_filename_query = ++ "INSERT INTO Filename (Name) " ++ "SELECT a.Name FROM " ++ "(SELECT DISTINCT Name FROM batch) AS a WHERE NOT EXISTS " ++ "(SELECT Name FROM Filename AS f WHERE f.Name = a.Name)"; ++#endif /* HAVE_BATCH_FILE_INSERT */ + + #endif /* HAVE_MYSQL */ +Index: src/cats/sql_create.c +=================================================================== +--- src/cats/sql_create.c (revision 5687) ++++ src/cats/sql_create.c (working copy) +@@ -668,6 +668,8 @@ + * }; + */ + ++#ifdef HAVE_BATCH_FILE_INSERT ++ + /* All sql_batch_* functions are used to do bulk batch insert in File/Filename/Path + * tables. This code can be activated by adding "#define HAVE_BATCH_FILE_INSERT 1" + * in baconfig.h +@@ -690,13 +692,13 @@ + + db_lock(mdb); + ok = db_sql_query(mdb, +- " CREATE TEMPORARY TABLE batch " +- " (fileindex integer, " +- " jobid integer, " +- " path blob, " +- " name blob, " +- " lstat tinyblob, " +- " md5 tinyblob) ",NULL, NULL); ++ "CREATE TEMPORARY TABLE batch (" ++ "FileIndex integer," ++ "JobId integer," ++ "Path blob," ++ "Name blob," ++ "LStat tinyblob," ++ "MD5 tinyblob)",NULL, NULL); + db_unlock(mdb); + return ok; + } +@@ -746,7 +748,6 @@ + return true; + } + +-#ifdef HAVE_BATCH_FILE_INSERT + /* + * Returns 1 if OK + * 0 if failed +@@ -794,7 +795,7 @@ + + if (!db_sql_query(jcr->db_batch,sql_batch_fill_filename_query, NULL,NULL)) { + Jmsg(jcr,M_FATAL,0,"Can't fill Filename table %s\n",jcr->db_batch->errmsg); +- QUERY_DB(jcr, jcr->db_batch, sql_batch_unlock_tables_query); ++ db_sql_query(jcr->db_batch, sql_batch_unlock_tables_query, NULL, NULL); + return false; + } + +@@ -804,12 +805,12 @@ + } + + if (!db_sql_query(jcr->db_batch, +- " INSERT INTO File (FileIndex, JobId, PathId, FilenameId, LStat, MD5)" +- " SELECT batch.FileIndex, batch.JobId, Path.PathId, " +- " Filename.FilenameId,batch.LStat, batch.MD5 " +- " FROM batch " +- " JOIN Path ON (batch.Path = Path.Path) " +- " JOIN Filename ON (batch.Name = Filename.Name) ", ++ "INSERT INTO File (FileIndex, JobId, PathId, FilenameId, LStat, MD5)" ++ "SELECT batch.FileIndex, batch.JobId, Path.PathId, " ++ "Filename.FilenameId,batch.LStat, batch.MD5 " ++ "FROM batch " ++ "JOIN Path ON (batch.Path = Path.Path) " ++ "JOIN Filename ON (batch.Name = Filename.Name)", + NULL,NULL)) + { + Jmsg(jcr, M_FATAL, 0, "Can't fill File table %s\n", jcr->db_batch->errmsg); +@@ -845,19 +846,24 @@ + mdb->db_port, + mdb->db_socket, + 1 /* multi_db = true */); ++ if (!jcr->db_batch) { ++ Mmsg1(&mdb->errmsg, _("Could not init batch database: \"%s\".\n"), ++ jcr->db->db_name); ++ Jmsg1(jcr, M_FATAL, 0, "%s", mdb->errmsg); ++ return false; ++ } + +- if (!jcr->db_batch || !db_open_database(jcr, jcr->db_batch)) { +- Jmsg(jcr, M_FATAL, 0, _("Could not open database \"%s\".\n"), +- jcr->db->db_name); +- if (jcr->db_batch) { +- Jmsg(jcr, M_FATAL, 0, "%s", db_strerror(jcr->db_batch)); +- } ++ if (!db_open_database(jcr, jcr->db_batch)) { ++ Mmsg2(&mdb->errmsg, _("Could not open database \"%s\": ERR=%s\n"), ++ jcr->db->db_name, db_strerror(jcr->db_batch)); ++ Jmsg1(jcr, M_FATAL, 0, "%s", mdb->errmsg); + return false; + } + + if (!sql_batch_start(jcr, jcr->db_batch)) { +- Jmsg(jcr, M_FATAL, 0, +- "Can't start batch mode %s", db_strerror(jcr->db_batch)); ++ Mmsg1(&mdb->errmsg, ++ "Can't start batch mode: ERR=%s", db_strerror(jcr->db_batch)); ++ Jmsg1(jcr, M_FATAL, 0, "%s", mdb->errmsg); + return false; + } + Dmsg3(100, "initdb ref=%d connected=%d db=%p\n", jcr->db_batch->ref_count, +@@ -870,10 +876,10 @@ + */ + if (!(ar->Stream == STREAM_UNIX_ATTRIBUTES || + ar->Stream == STREAM_UNIX_ATTRIBUTES_EX)) { +- Mmsg1(&bdb->errmsg, _("Attempt to put non-attributes into catalog. Stream=%d\n"), ++ Mmsg1(&mdb->errmsg, _("Attempt to put non-attributes into catalog. Stream=%d\n"), + ar->Stream); +- Jmsg(jcr, M_ERROR, 0, "%s", bdb->errmsg); +- return 0; ++ Jmsg(jcr, M_FATAL, 0, "%s", mdb->errmsg); ++ return false; + } + + split_path_and_file(jcr, bdb, ar->fname); +Index: src/cats/postgresql.c +=================================================================== +--- src/cats/postgresql.c (revision 5687) ++++ src/cats/postgresql.c (working copy) +@@ -605,13 +605,13 @@ + Dmsg0(500, "my_postgresql_batch_start started\n"); + + if (my_postgresql_query(mdb, +- " CREATE TEMPORARY TABLE batch " +- " (fileindex int, " +- " jobid int, " +- " path varchar, " +- " name varchar, " +- " lstat varchar, " +- " md5 varchar)") == 1) ++ "CREATE TEMPORARY TABLE batch (" ++ "fileindex int," ++ "jobid int," ++ "path varchar," ++ "name varchar," ++ "lstat varchar," ++ "md5 varchar)") == 1) + { + Dmsg0(500, "my_postgresql_batch_start failed\n"); + return 1; +@@ -785,22 +785,29 @@ + return dest; + } + +-char *my_pg_batch_lock_path_query = "BEGIN; LOCK TABLE Path IN SHARE ROW EXCLUSIVE MODE"; ++#ifdef HAVE_BATCH_FILE_INSERT ++const char *my_pg_batch_lock_path_query = ++ "BEGIN; LOCK TABLE Path IN SHARE ROW EXCLUSIVE MODE"; + + +-char *my_pg_batch_lock_filename_query = "BEGIN; LOCK TABLE Filename IN SHARE ROW EXCLUSIVE MODE"; ++const char *my_pg_batch_lock_filename_query = ++ "BEGIN; LOCK TABLE Filename IN SHARE ROW EXCLUSIVE MODE"; + +-char *my_pg_batch_unlock_tables_query = "COMMIT"; ++const char *my_pg_batch_unlock_tables_query = "COMMIT"; + +-char *my_pg_batch_fill_path_query = "INSERT INTO Path (Path) " +- " SELECT a.Path FROM " +- " (SELECT DISTINCT Path FROM batch) AS a " +- " WHERE NOT EXISTS (SELECT Path FROM Path WHERE Path = a.Path) "; ++const char *my_pg_batch_fill_path_query = ++ "INSERT INTO Path (Path) " ++ "SELECT a.Path FROM " ++ "(SELECT DISTINCT Path FROM batch) AS a " ++ "WHERE NOT EXISTS (SELECT Path FROM Path WHERE Path = a.Path) "; + + +-char *my_pg_batch_fill_filename_query = "INSERT INTO Filename (Name) " +- " SELECT a.Name FROM " +- " (SELECT DISTINCT Name FROM batch) as a " +- " WHERE NOT EXISTS " +- " (SELECT Name FROM Filename WHERE Name = a.Name)"; ++const char *my_pg_batch_fill_filename_query = ++ "INSERT INTO Filename (Name) " ++ "SELECT a.Name FROM " ++ "(SELECT DISTINCT Name FROM batch) as a " ++ "WHERE NOT EXISTS " ++ "(SELECT Name FROM Filename WHERE Name = a.Name)"; ++#endif /* HAVE_BATCH_FILE_INSERT */ ++ + #endif /* HAVE_POSTGRESQL */ diff --git a/bacula/src/dird/job.c b/bacula/src/dird/job.c index df9751a212..1ffecf1db6 100644 --- a/bacula/src/dird/job.c +++ b/bacula/src/dird/job.c @@ -237,8 +237,7 @@ static void *job_thread(void *arg) { JCR *jcr = (JCR *)arg; - jcr->my_thread_id = pthread_self(); - pthread_detach(jcr->my_thread_id); + pthread_detach(pthread_self()); Dsm_check(1); Dmsg0(200, "=====Start Job=========\n"); diff --git a/bacula/src/dird/jobq.c b/bacula/src/dird/jobq.c index 768d6b34c8..f3a9e794bf 100644 --- a/bacula/src/dird/jobq.c +++ b/bacula/src/dird/jobq.c @@ -1,22 +1,3 @@ -/* - * Bacula job queue routines. - * - * This code consists of three queues, the waiting_jobs - * queue, where jobs are initially queued, the ready_jobs - * queue, where jobs are placed when all the resources are - * allocated and they can immediately be run, and the - * running queue where jobs are placed when they are - * running. - * - * Kern Sibbald, July MMIII - * - * Version $Id$ - * - * This code was adapted from the Bacula workq, which was - * adapted from "Programming with POSIX Threads", by - * David R. Butenhof - * - */ /* Bacula® - The Network Backup Solution @@ -44,6 +25,25 @@ (FSFE), Fiduciary Program, Sumatrastrasse 25, 8006 Zürich, Switzerland, email:ftf@fsfeurope.org. */ +/* + * Bacula job queue routines. + * + * This code consists of three queues, the waiting_jobs + * queue, where jobs are initially queued, the ready_jobs + * queue, where jobs are placed when all the resources are + * allocated and they can immediately be run, and the + * running queue where jobs are placed when they are + * running. + * + * Kern Sibbald, July MMIII + * + * Version $Id$ + * + * This code was adapted from the Bacula workq, which was + * adapted from "Programming with POSIX Threads", by + * David R. Butenhof + * + */ #include "bacula.h" #include "dird.h" @@ -453,6 +453,7 @@ void *jobq_server(void *arg) } } jq->running_jobs->append(je); + set_jcr_in_tsd(jcr); Dmsg1(2300, "Took jobid=%d from ready and appended to run\n", jcr->JobId); /* Release job queue lock */ diff --git a/bacula/src/dird/msgchan.c b/bacula/src/dird/msgchan.c index bca443577f..37a63cbbb2 100644 --- a/bacula/src/dird/msgchan.c +++ b/bacula/src/dird/msgchan.c @@ -364,6 +364,7 @@ extern "C" void *msg_thread(void *arg) int stat; pthread_detach(pthread_self()); + set_jcr_in_tsd(jcr); jcr->SD_msg_chan = pthread_self(); pthread_cleanup_push(msg_thread_cleanup, arg); sd = jcr->store_bsock; diff --git a/bacula/src/lib/crypto.c b/bacula/src/lib/crypto.c index 1c957b0f6d..6f5367a6ca 100644 --- a/bacula/src/lib/crypto.c +++ b/bacula/src/lib/crypto.c @@ -451,14 +451,14 @@ int crypto_keypair_load_cert(X509_KEYPAIR *keypair, const char *file) /* Extract the subjectKeyIdentifier extension field */ if ((keypair->keyid = openssl_cert_keyid(cert)) == NULL) { - Jmsg0(get_jcr_from_tid(), M_ERROR, 0, + Jmsg0(NULL, M_ERROR, 0, _("Provided certificate does not include the required subjectKeyIdentifier extension.")); goto err; } /* Validate the public key type (only RSA is supported) */ if (EVP_PKEY_type(keypair->pubkey->type) != EVP_PKEY_RSA) { - Jmsg1(get_jcr_from_tid(), M_ERROR, 0, + Jmsg1(NULL, M_ERROR, 0, _("Unsupported key type provided: %d\n"), EVP_PKEY_type(keypair->pubkey->type)); goto err; } @@ -1033,7 +1033,7 @@ CRYPTO_SESSION *crypto_session_new (crypto_cipher_t cipher, alist *pubkeys) ec = EVP_bf_cbc(); break; default: - Jmsg0(get_jcr_from_tid(), M_ERROR, 0, _("Unsupported cipher type specified\n")); + Jmsg0(NULL, M_ERROR, 0, _("Unsupported cipher type specified\n")); crypto_session_free(cs); return NULL; } @@ -1276,7 +1276,7 @@ CIPHER_CONTEXT *crypto_cipher_new(CRYPTO_SESSION *cs, bool encrypt, uint32_t *bl * Acquire a cipher instance for the given ASN.1 cipher NID */ if ((ec = EVP_get_cipherbyobj(cs->cryptoData->contentEncryptionAlgorithm)) == NULL) { - Jmsg1(get_jcr_from_tid(), M_ERROR, 0, + Jmsg1(NULL, M_ERROR, 0, _("Unsupported contentEncryptionAlgorithm: %d\n"), OBJ_obj2nid(cs->cryptoData->contentEncryptionAlgorithm)); free(cipher_ctx); return NULL; @@ -1381,7 +1381,7 @@ int init_crypto (void) if ((stat = openssl_init_threads()) != 0) { berrno be; - Jmsg1(get_jcr_from_tid(), M_ABORT, 0, + Jmsg1(NULL, M_ABORT, 0, _("Unable to init OpenSSL threading: ERR=%s\n"), be.bstrerror(stat)); } @@ -1395,7 +1395,7 @@ int init_crypto (void) OpenSSL_add_all_algorithms(); if (!openssl_seed_prng()) { - Jmsg0(get_jcr_from_tid(), M_ERROR_TERM, 0, _("Failed to seed OpenSSL PRNG\n")); + Jmsg0(NULL, M_ERROR_TERM, 0, _("Failed to seed OpenSSL PRNG\n")); } crypto_initialized = true; @@ -1421,7 +1421,7 @@ int cleanup_crypto (void) } if (!openssl_save_prng()) { - Jmsg0(get_jcr_from_tid(), M_ERROR, 0, _("Failed to save OpenSSL PRNG\n")); + Jmsg0(NULL, M_ERROR, 0, _("Failed to save OpenSSL PRNG\n")); } openssl_cleanup_threads(); @@ -1502,7 +1502,7 @@ bool crypto_digest_update(DIGEST *digest, const uint8_t *data, uint32_t length) if ((ret = SHA1Update(&digest->sha1, (const u_int8_t *) data, length)) == shaSuccess) { return true; } else { - Jmsg1(get_jcr_from_tid(), M_ERROR, 0, _("SHA1Update() returned an error: %d\n"), ret); + Jmsg1(NULL, M_ERROR, 0, _("SHA1Update() returned an error: %d\n"), ret); return false; } break; diff --git a/bacula/src/lib/jcr.c b/bacula/src/lib/jcr.c index 58921659da..ae4e40e9ec 100644 --- a/bacula/src/lib/jcr.c +++ b/bacula/src/lib/jcr.c @@ -55,6 +55,14 @@ const int dbglvl = 3400; +/* + * Setting a NULL in tsd doesn't clear the tsd but instead tells + * pthreads not to call the tsd destructor. Consequently, we + * define this *invalid* jcr address and stuff it in the tsd + * when the jcr is no longer valid. + */ +#define INVALID_JCR ((JCR *)(-1)) + /* External variables we reference */ extern time_t watchdog_time; @@ -86,6 +94,10 @@ static pthread_mutex_t job_start_mutex = PTHREAD_MUTEX_INITIALIZER; static pthread_mutex_t last_jobs_mutex = PTHREAD_MUTEX_INITIALIZER; +static pthread_key_t jcr_key; /* Pointer to jcr for each thread */ + +pthread_once_t key_once = PTHREAD_ONCE_INIT; + void lock_jobs() { @@ -230,6 +242,16 @@ static void job_end_pop(JCR *jcr) } } +void create_jcr_key() +{ + int status = pthread_key_create(&jcr_key, NULL); + if (status != 0) { + berrno be; + Jmsg1(NULL, M_ABORT, 0, _("pthread key create failed: ERR=%s\n"), + be.bstrerror(status)); + } +} + /* * Create a Job Control Record and link it into JCR chain * Returns newly allocated JCR @@ -241,8 +263,14 @@ JCR *new_jcr(int size, JCR_free_HANDLER *daemon_free_jcr) JCR *jcr; MQUEUE_ITEM *item = NULL; struct sigaction sigtimer; + int status; Dmsg0(dbglvl, "Enter new_jcr\n"); + status = pthread_once(&key_once, create_jcr_key); + if (status != 0) { + berrno be; + Jmsg1(NULL, M_ABORT, 0, _("pthread_once failed. ERR=%s\n"), be.bstrerror(status)); + } jcr = (JCR *)malloc(size); memset(jcr, 0, size); jcr->my_thread_id = pthread_self(); @@ -262,7 +290,7 @@ JCR *new_jcr(int size, JCR_free_HANDLER *daemon_free_jcr) jcr->JobType = JT_SYSTEM; /* internal job until defined */ jcr->JobLevel = L_NONE; set_jcr_job_status(jcr, JS_Created); /* ready to run */ - + set_jcr_in_tsd(jcr); sigtimer.sa_flags = 0; sigtimer.sa_handler = timeout_handler; sigfillset(&sigtimer.sa_mask); @@ -407,6 +435,8 @@ static void free_common_jcr(JCR *jcr) free_guid_list(jcr->id_list); jcr->id_list = NULL; } + /* Invalidate the tsd jcr data */ + set_jcr_in_tsd(INVALID_JCR); free(jcr); } @@ -461,54 +491,43 @@ void free_jcr(JCR *jcr) garbage_collect_memory_pool(); Dmsg0(dbglvl, "Exit free_jcr\n"); } - -/* - * Find which JobId corresponds to the current thread - */ -uint32_t get_jobid_from_tid() + +void set_jcr_in_tsd(JCR *jcr) { - return get_jobid_from_tid(pthread_self()); + int status = pthread_setspecific(jcr_key, (void *)jcr); + if (status != 0) { + berrno be; + Jmsg1(jcr, M_ABORT, 0, _("pthread_setspecific failed: ERR=%s\n"), be.bstrerror(status)); + } } -uint32_t get_jobid_from_tid(pthread_t tid) +JCR *get_jcr_from_tsd() { - JCR *jcr; - uint32_t JobId = 0; - foreach_jcr(jcr) { - if (pthread_equal(jcr->my_thread_id, tid)) { - JobId = (uint32_t)jcr->JobId; - break; - } + JCR *jcr = (JCR *)pthread_getspecific(jcr_key); +// printf("get_jcr_from_tsd: jcr=%p\n", jcr); + /* set any INVALID_JCR to NULL which the rest of Bacula understands */ + if (jcr == INVALID_JCR) { + jcr = NULL; } - endeach_jcr(jcr); - return JobId; + return jcr; } + /* - * Find the jcr that corresponds to the current thread + * Find which JobId corresponds to the current thread */ -JCR *get_jcr_from_tid() -{ - return get_jcr_from_tid(pthread_self()); -} - -JCR *get_jcr_from_tid(pthread_t tid) +uint32_t get_jobid_from_tsd() { JCR *jcr; - JCR *rtn_jcr = NULL; - - foreach_jcr(jcr) { - if (pthread_equal(jcr->my_thread_id, tid)) { - rtn_jcr = jcr; - break; - } + uint32_t JobId = 0; + jcr = get_jcr_from_tsd(); +// printf("get_jobid_from_tsr: jcr=%p\n", jcr); + if (jcr) { + JobId = (uint32_t)jcr->JobId; } - endeach_jcr(jcr); - return rtn_jcr; + return JobId; } - - /* * Given a JobId, find the JCR * Returns: jcr on success diff --git a/bacula/src/lib/message.c b/bacula/src/lib/message.c index 1ce1f85fc6..2e1e9ff8cd 100644 --- a/bacula/src/lib/message.c +++ b/bacula/src/lib/message.c @@ -60,19 +60,6 @@ char con_fname[500]; /* Console filename */ FILE *con_fd = NULL; /* Console file descriptor */ brwlock_t con_lock; /* Console lock structure */ -static char *catalog_db = NULL; /* database type */ -static void (*message_callback)(int type, char *msg) = NULL; - -const char *host_os = HOST_OS; -const char *distname = DISTNAME; -const char *distver = DISTVER; -static FILE *trace_fd = NULL; -#if defined(HAVE_WIN32) -static bool trace = true; -#else -static bool trace = false; -#endif - /* Forward referenced functions */ /* Imported functions */ @@ -83,6 +70,20 @@ static bool trace = false; /* Used to allow only one thread close the daemon messages at a time */ static pthread_mutex_t mutex = PTHREAD_MUTEX_INITIALIZER; static MSGS *daemon_msgs; /* global messages */ +static char *catalog_db = NULL; /* database type */ +static void (*message_callback)(int type, char *msg) = NULL; +static FILE *trace_fd = NULL; +#if defined(HAVE_WIN32) +static bool trace = true; +#else +static bool trace = false; +#endif + +/* Constants */ +const char *host_os = HOST_OS; +const char *distname = DISTNAME; +const char *distver = DISTVER; + void register_message_callback(void msg_callback(int type, char *msg)) { @@ -581,8 +582,7 @@ static bool open_dest_file(JCR *jcr, DEST *d, const char *mode) if (!d->fd) { berrno be; d->fd = stdout; - Qmsg2(jcr, M_ERROR, 0, _("fopen %s failed: ERR=%s\n"), d->where, - be.bstrerror()); + Qmsg2(jcr, M_ERROR, 0, _("fopen %s failed: ERR=%s\n"), d->where, be.bstrerror()); d->fd = NULL; return false; } @@ -638,6 +638,9 @@ void dispatch_message(JCR *jcr, int type, time_t mtime, char *msg) /* Now figure out where to send the message */ msgs = NULL; + if (!jcr) { + jcr = get_jcr_from_tsd(); + } if (jcr) { msgs = jcr->jcr_msgs; } @@ -849,8 +852,8 @@ d_msg(const char *file, int line, int level, const char *fmt,...) if (level <= debug_level) { #ifdef FULL_LOCATION if (details) { - len = bsnprintf(buf, sizeof(buf), "%s: %s:%d jid=%u ", - my_name, get_basename(file), line, get_jobid_from_tid()); + len = bsnprintf(buf, sizeof(buf), "%s: %s:%d-%u ", + my_name, get_basename(file), line, get_jobid_from_tsd()); } else { len = 0; } @@ -1091,6 +1094,9 @@ Jmsg(JCR *jcr, int type, time_t mtime, const char *fmt,...) msgs = NULL; job = NULL; + if (!jcr) { + jcr = get_jcr_from_tsd(); + } if (jcr) { msgs = jcr->jcr_msgs; job = jcr->Job; @@ -1328,10 +1334,13 @@ void Qmsg(JCR *jcr, int type, time_t mtime, const char *fmt,...) item->type = type; item->mtime = time(NULL); strcpy(item->msg, pool_buf); + if (!jcr) { + jcr = get_jcr_from_tsd(); + } /* If no jcr or dequeuing send to daemon to avoid recursion */ if (!jcr || jcr->dequeuing) { /* jcr==NULL => daemon message, safe to send now */ - Jmsg(NULL, item->type, item->mtime, "%s", item->msg); + Jmsg(jcr, item->type, item->mtime, "%s", item->msg); free(item); } else { /* Queue message for later sending */ diff --git a/bacula/src/lib/openssl.c b/bacula/src/lib/openssl.c index 7f161d71d1..014ed4026b 100644 --- a/bacula/src/lib/openssl.c +++ b/bacula/src/lib/openssl.c @@ -66,7 +66,7 @@ struct CRYPTO_dynlock_value { */ void openssl_post_errors(int code, const char *errstring) { - openssl_post_errors(get_jcr_from_tid(), code, errstring); + openssl_post_errors(NULL, code, errstring); } @@ -115,8 +115,7 @@ static struct CRYPTO_dynlock_value *openssl_create_dynamic_mutex (const char *fi if ((stat = pthread_mutex_init(&dynlock->mutex, NULL)) != 0) { berrno be; - Jmsg1(get_jcr_from_tid(), M_ABORT, 0, _("Unable to init mutex: ERR=%s\n"), - be.bstrerror(stat)); + Jmsg1(NULL, M_ABORT, 0, _("Unable to init mutex: ERR=%s\n"), be.bstrerror(stat)); } return dynlock; @@ -137,8 +136,7 @@ static void openssl_destroy_dynamic_mutex(struct CRYPTO_dynlock_value *dynlock, if ((stat = pthread_mutex_destroy(&dynlock->mutex)) != 0) { berrno be; - Jmsg1(get_jcr_from_tid(), M_ABORT, 0, _("Unable to destroy mutex: ERR=%s\n"), - be.bstrerror(stat)); + Jmsg1(NULL, M_ABORT, 0, _("Unable to destroy mutex: ERR=%s\n"), be.bstrerror(stat)); } free(dynlock); @@ -176,8 +174,7 @@ int openssl_init_threads (void) for (i = 0; i < numlocks; i++) { if ((stat = pthread_mutex_init(&mutexes[i], NULL)) != 0) { berrno be; - Jmsg1(get_jcr_from_tid(), M_ERROR, 0, _("Unable to init mutex: ERR=%s\n"), - be.bstrerror(stat)); + Jmsg1(NULL, M_FATAL, 0, _("Unable to init mutex: ERR=%s\n"), be.bstrerror(stat)); return stat; } } @@ -210,7 +207,7 @@ void openssl_cleanup_threads(void) if ((stat = pthread_mutex_destroy(&mutexes[i])) != 0) { berrno be; /* We don't halt execution, reporting the error should be sufficient */ - Jmsg1(get_jcr_from_tid(), M_ERROR, 0, _("Unable to destroy mutex: ERR=%s\n"), + Jmsg1(NULL, M_ERROR, 0, _("Unable to destroy mutex: ERR=%s\n"), be.bstrerror(stat)); } } diff --git a/bacula/src/lib/protos.h b/bacula/src/lib/protos.h index 043a40a6b9..6f555ed5f1 100644 --- a/bacula/src/lib/protos.h +++ b/bacula/src/lib/protos.h @@ -199,10 +199,9 @@ void unlock_jobs(); JCR *jcr_walk_start(); JCR *jcr_walk_next(JCR *prev_jcr); void jcr_walk_end(JCR *jcr); -uint32_t get_jobid_from_tid(pthread_t tid); -uint32_t get_jobid_from_tid(); -JCR *get_jcr_from_tid(pthread_t tid); -JCR *get_jcr_from_tid(); +uint32_t get_jobid_from_tsd(); +JCR *get_jcr_from_tsd(); +void set_jcr_in_tsd(JCR *jcr); /* lex.c */ diff --git a/bacula/src/lib/tls.c b/bacula/src/lib/tls.c index 71a6fa2841..f8062c073a 100644 --- a/bacula/src/lib/tls.c +++ b/bacula/src/lib/tls.c @@ -90,9 +90,9 @@ static int openssl_verify_peer(int ok, X509_STORE_CTX *store) X509_NAME_oneline(X509_get_issuer_name(cert), issuer, 256); X509_NAME_oneline(X509_get_subject_name(cert), subject, 256); - Jmsg5(get_jcr_from_tid(), M_ERROR, 0, _("Error with certificate at depth: %d, issuer = %s," - " subject = %s, ERR=%d:%s\n"), depth, issuer, - subject, err, X509_verify_cert_error_string(err)); + Jmsg5(NULL, M_ERROR, 0, _("Error with certificate at depth: %d, issuer = %s," + " subject = %s, ERR=%d:%s\n"), depth, issuer, + subject, err, X509_verify_cert_error_string(err)); } @@ -153,7 +153,7 @@ TLS_CONTEXT *new_tls_context(const char *ca_certfile, const char *ca_certdir, } } else if (verify_peer) { /* At least one CA is required for peer verification */ - Jmsg0(get_jcr_from_tid(), M_ERROR, 0, _("Either a certificate file or a directory must be" + Jmsg0(NULL, M_ERROR, 0, _("Either a certificate file or a directory must be" " specified as a verification store\n")); goto err; } @@ -199,7 +199,7 @@ TLS_CONTEXT *new_tls_context(const char *ca_certfile, const char *ca_certdir, } if (SSL_CTX_set_cipher_list(ctx->openssl, TLS_DEFAULT_CIPHERS) != 1) { - Jmsg0(get_jcr_from_tid(), M_ERROR, 0, + Jmsg0(NULL, M_ERROR, 0, _("Error setting cipher list, no valid ciphers available\n")); goto err; } @@ -259,7 +259,7 @@ bool tls_postconnect_verify_cn(TLS_CONNECTION *tls, alist *verify_list) /* Check if peer provided a certificate */ if (!(cert = SSL_get_peer_certificate(ssl))) { - Jmsg0(get_jcr_from_tid(), M_ERROR, 0, _("Peer failed to present a TLS certificate\n")); + Jmsg0(NULL, M_ERROR, 0, _("Peer failed to present a TLS certificate\n")); return false; } @@ -301,7 +301,7 @@ bool tls_postconnect_verify_host(TLS_CONNECTION *tls, const char *host) /* Check if peer provided a certificate */ if (!(cert = SSL_get_peer_certificate(ssl))) { - Jmsg1(get_jcr_from_tid(), M_ERROR, 0, + Jmsg1(NULL, M_ERROR, 0, _("Peer %s failed to present a TLS certificate\n"), host); return false; } diff --git a/bacula/src/stored/dev.c b/bacula/src/stored/dev.c index f0e1684ce7..feaab57d33 100644 --- a/bacula/src/stored/dev.c +++ b/bacula/src/stored/dev.c @@ -490,7 +490,7 @@ void DEVICE::open_file_device(DCR *dcr, int omode) Mmsg2(errmsg, _("Could not open: %s, ERR=%s\n"), archive_name.c_str(), be.bstrerror()); Dmsg1(100, "open failed: %s", errmsg); - Emsg0(M_FATAL, 0, errmsg); + Jmsg1(NULL, M_WARNING, 0, "%s", errmsg); } else { dev_errno = 0; file = 0; diff --git a/bacula/src/stored/reserve.c b/bacula/src/stored/reserve.c index e45fa752ea..70083683bc 100644 --- a/bacula/src/stored/reserve.c +++ b/bacula/src/stored/reserve.c @@ -39,8 +39,6 @@ #include "bacula.h" #include "stored.h" -#define jid() ((uint32_t)get_jobid_from_tid()) - const int dbglvl = 50; static dlist *vol_list = NULL; @@ -178,7 +176,7 @@ static void debug_list_volumes(const char *imsg) } else { Mmsg(msg, "List from %s: %s at %p no dev\n", imsg, vol->vol_name, vol->vol_name); } - Dmsg2(dbglvl, "jid=%u %s", jid(), msg.c_str()); + Dmsg1(dbglvl, "%s", msg.c_str()); } #ifdef xxx @@ -234,7 +232,7 @@ static VOLRES *new_vol_item(DCR *dcr, const char *VolumeName) memset(vol, 0, sizeof(VOLRES)); vol->vol_name = bstrdup(VolumeName); vol->dev = dcr->dev; - Dmsg4(dbglvl, "jid=%u new Vol=%s at %p dev=%s\n", (int)dcr->jcr->JobId, + Dmsg3(dbglvl, "new Vol=%s at %p dev=%s\n", VolumeName, vol->vol_name, vol->dev->print_name()); return vol; } @@ -310,7 +308,7 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName) ASSERT(dev != NULL); - Dmsg2(dbglvl, "jid=%u reserve_volume %s\n", jid(), VolumeName); + Dmsg1(dbglvl, "reserve_volume %s\n", VolumeName); /* * We lock the reservations system here to ensure * when adding a new volume that no newly scheduled @@ -329,11 +327,11 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName) * because it was probably inserted by another job. */ if (strcmp(vol->vol_name, VolumeName) == 0) { - Dmsg2(dbglvl, "jid=%u OK, vol=%s on device.\n", (int)dcr->jcr->JobId, VolumeName); + Dmsg1(dbglvl, "OK, vol=%s on device.\n", VolumeName); goto get_out; /* Volume already on this device */ } else { - Dmsg3(dbglvl, "jid=%u reserve_vol free vol=%s at %p\n", - (int)dcr->jcr->JobId, vol->vol_name, vol->vol_name); + Dmsg2(dbglvl, "reserve_vol free vol=%s at %p\n", + vol->vol_name, vol->vol_name); debug_list_volumes("reserve_vol free"); vol_list->remove(vol); free_vol_item(vol); @@ -348,14 +346,14 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName) */ vol = (VOLRES *)vol_list->binary_insert(nvol, my_compare); if (vol != nvol) { - Dmsg3(dbglvl, "jid=%u Found vol=%s dev-same=%d\n", jid(), vol->vol_name, dev==vol->dev); + Dmsg2(dbglvl, "Found vol=%s dev-same=%d\n", vol->vol_name, dev==vol->dev); /* * At this point, a Volume with this name already is in the list, * so we simply release our new Volume entry. Note, this should * only happen if we are moving the volume from one drive to another. */ - Dmsg3(dbglvl, "jid=%u reserve_vol free-tmp vol=%s at %p\n", - (int)dcr->jcr->JobId, vol->vol_name, vol->vol_name); + Dmsg2(dbglvl, "reserve_vol free-tmp vol=%s at %p\n", + vol->vol_name, vol->vol_name); /* * Clear dev pointer so that free_vol_item() doesn't * take away our volume. @@ -368,7 +366,7 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName) /* Caller wants to switch Volume to another device */ if (!vol->dev->is_busy()) { /* OK to move it -- I'm not sure this will work */ - Dmsg4(dbglvl, "==== jid=%u Swap vol=%s from dev=%s to %s\n", jid(), VolumeName, + Dmsg3(dbglvl, "==== Swap vol=%s from dev=%s to %s\n", VolumeName, vol->dev->print_name(), dev->print_name()); vol->dev->vol = NULL; /* take vol from old drive */ vol->dev->VolHdr.VolumeName[0] = 0; @@ -376,8 +374,8 @@ VOLRES *reserve_volume(DCR *dcr, const char *VolumeName) dev->vol = vol; /* point dev at vol */ dev->VolHdr.VolumeName[0] = 0; } else { - Dmsg4(dbglvl, "jid=%u Volume busy could not swap vol=%s from dev=%s to %s\n", - jid(), VolumeName, vol->dev->print_name(), dev->print_name()); + Dmsg3(dbglvl, "Volume busy could not swap vol=%s from dev=%s to %s\n", + VolumeName, vol->dev->print_name(), dev->print_name()); vol = NULL; /* device busy */ } } @@ -404,7 +402,7 @@ VOLRES *find_volume(DCR *dcr) vol.vol_name = bstrdup(dcr->VolumeName); fvol = (VOLRES *)vol_list->binary_search(&vol, my_compare); free(vol.vol_name); - Dmsg3(dbglvl, "jid=%u find_vol=%s found=%d\n", jid(), dcr->VolumeName, fvol!=NULL); + Dmsg2(dbglvl, "find_vol=%s found=%d\n", dcr->VolumeName, fvol!=NULL); debug_list_volumes("find_volume"); unlock_volumes(); return fvol; @@ -420,7 +418,7 @@ void unreserve_device(DCR *dcr) if (dcr->reserved_device) { dcr->reserved_device = false; dev->reserved_device--; - Dmsg3(dbglvl, "jid=%u Dec reserve=%d dev=%s\n", jid(), dev->reserved_device, dev->print_name()); + Dmsg2(dbglvl, "Dec reserve=%d dev=%s\n", dev->reserved_device, dev->print_name()); dcr->reserved_device = false; /* If we set read mode in reserving, remove it */ if (dev->can_read()) { @@ -446,13 +444,13 @@ bool volume_unused(DCR *dcr) DEVICE *dev = dcr->dev; if (dev->vol == NULL) { - Dmsg2(dbglvl, "jid=%u vol_unused: no vol on %s\n", (int)dcr->jcr->JobId, dev->print_name()); + Dmsg1(dbglvl, "vol_unused: no vol on %s\n", dev->print_name()); debug_list_volumes("null vol cannot unreserve_volume"); return false; } if (dev->is_busy()) { - Dmsg2(dbglvl, "jid=%u vol_unused: no vol on %s\n", (int)dcr->jcr->JobId, dev->print_name()); + Dmsg1(dbglvl, "vol_unused: no vol on %s\n", dev->print_name()); debug_list_volumes("dev busy cannot unreserve_volume"); return false; } @@ -478,14 +476,14 @@ bool free_volume(DEVICE *dev) VOLRES *vol; if (dev->vol == NULL) { - Dmsg2(dbglvl, "jid=%u No vol on dev %s\n", jid(), dev->print_name()); + Dmsg1(dbglvl, "No vol on dev %s\n", dev->print_name()); return false; } lock_volumes(); vol = dev->vol; dev->vol = NULL; vol_list->remove(vol); - Dmsg3(dbglvl, "jid=%u free_volume %s dev=%s\n", jid(), vol->vol_name, dev->print_name()); + Dmsg2(dbglvl, "free_volume %s dev=%s\n", vol->vol_name, dev->print_name()); free_vol_item(vol); debug_list_volumes("free_volume"); unlock_volumes(); @@ -512,11 +510,9 @@ void free_volume_list() lock_volumes(); foreach_dlist(vol, vol_list) { if (vol->dev) { - Dmsg3(dbglvl, "jid=%u free vol_list Volume=%s dev=%s\n", jid(), - vol->vol_name, vol->dev->print_name()); + Dmsg2(dbglvl, "free vol_list Volume=%s dev=%s\n", vol->vol_name, vol->dev->print_name()); } else { - Dmsg3(dbglvl, "jid=%u free vol_list Volume=%s dev=%p\n", jid(), - vol->vol_name, vol->dev); + Dmsg2(dbglvl, "free vol_list Volume=%s dev=%p\n", vol->vol_name, vol->dev); } free(vol->vol_name); vol->vol_name = NULL; @@ -530,25 +526,25 @@ bool is_volume_in_use(DCR *dcr) { VOLRES *vol = find_volume(dcr); if (!vol) { - Dmsg2(dbglvl, "jid=%u Vol=%s not in use.\n", jid(), dcr->VolumeName); + Dmsg1(dbglvl, "Vol=%s not in use.\n", dcr->VolumeName); return false; /* vol not in list */ } ASSERT(vol->dev != NULL); if (dcr->dev == vol->dev) { /* same device OK */ - Dmsg2(dbglvl, "jid=%u Vol=%s on same dev.\n", jid(), dcr->VolumeName); + Dmsg1(dbglvl, "Vol=%s on same dev.\n", dcr->VolumeName); return false; } else { - Dmsg4(dbglvl, "jid=%u Vol=%s on %s we have %s\n", jid(), dcr->VolumeName, + Dmsg3(dbglvl, "Vol=%s on %s we have %s\n", dcr->VolumeName, vol->dev->print_name(), dcr->dev->print_name()); } if (!vol->dev->is_busy()) { - Dmsg3(dbglvl, "jid=%u Vol=%s dev=%s not busy.\n", jid(), dcr->VolumeName, vol->dev->print_name()); + Dmsg2(dbglvl, "Vol=%s dev=%s not busy.\n", dcr->VolumeName, vol->dev->print_name()); return false; } else { - Dmsg3(dbglvl, "jid=%u Vol=%s dev=%s busy.\n", jid(), dcr->VolumeName, vol->dev->print_name()); + Dmsg2(dbglvl, "Vol=%s dev=%s busy.\n", dcr->VolumeName, vol->dev->print_name()); } - Dmsg3(dbglvl, "jid=%u Vol=%s in use by %s.\n", jid(), dcr->VolumeName, vol->dev->print_name()); + Dmsg2(dbglvl, "Vol=%s in use by %s.\n", dcr->VolumeName, vol->dev->print_name()); return true; } @@ -584,7 +580,7 @@ static bool use_storage_cmd(JCR *jcr) dirstore = New(alist(10, not_owned_by_alist)); jcr->reserve_msgs = New(alist(10, not_owned_by_alist)); do { - Dmsg2(dbglvl, "jid=%u msg); + Dmsg1(dbglvl, "msg); ok = sscanf(dir->msg, use_storage, store_name.c_str(), media_type.c_str(), pool_name.c_str(), pool_type.c_str(), &append, &Copy, &Stripe) == 7; @@ -613,7 +609,7 @@ static bool use_storage_cmd(JCR *jcr) /* Now get all devices */ while (dir->recv() >= 0) { - Dmsg2(dbglvl, "jid=%u msg); + Dmsg1(dbglvl, "msg); ok = sscanf(dir->msg, use_device, dev_name.c_str()) == 1; if (!ok) { break; @@ -627,12 +623,11 @@ static bool use_storage_cmd(JCR *jcr) char *device_name; if (debug_level >= dbglvl) { foreach_alist(store, dirstore) { - Dmsg6(dbglvl, "jid=%u Storage=%s media_type=%s pool=%s pool_type=%s append=%d\n", - (int)rctx.jcr->JobId, + Dmsg5(dbglvl, "Storage=%s media_type=%s pool=%s pool_type=%s append=%d\n", store->name, store->media_type, store->pool_name, store->pool_type, store->append); foreach_alist(device_name, store->device) { - Dmsg2(dbglvl, "jid=%u Device=%s\n", jid(), device_name); + Dmsg1(dbglvl, " Device=%s\n", device_name); } } } @@ -678,8 +673,7 @@ static bool use_storage_cmd(JCR *jcr) rctx.PreferMountedVols = false; rctx.exact_match = false; rctx.autochanger_only = true; - Dmsg6(dbglvl, "jid=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", - (int)rctx.jcr->JobId, + Dmsg5(dbglvl, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); if ((ok = find_suitable_device_for_job(jcr, rctx))) { @@ -694,8 +688,7 @@ static bool use_storage_cmd(JCR *jcr) rctx.try_low_use_drive = false; } rctx.autochanger_only = false; - Dmsg6(dbglvl, "jid=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", - (int)rctx.jcr->JobId, + Dmsg5(dbglvl, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); if ((ok = find_suitable_device_for_job(jcr, rctx))) { @@ -710,8 +703,7 @@ static bool use_storage_cmd(JCR *jcr) rctx.PreferMountedVols = true; rctx.exact_match = true; rctx.autochanger_only = false; - Dmsg6(dbglvl, "jid=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", - (int)rctx.jcr->JobId, + Dmsg5(dbglvl, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); if ((ok = find_suitable_device_for_job(jcr, rctx))) { @@ -719,8 +711,7 @@ static bool use_storage_cmd(JCR *jcr) } /* Look for any mounted drive */ rctx.exact_match = false; - Dmsg6(dbglvl, "jid=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", - (int)rctx.jcr->JobId, + Dmsg5(dbglvl, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); if ((ok = find_suitable_device_for_job(jcr, rctx))) { @@ -728,8 +719,7 @@ static bool use_storage_cmd(JCR *jcr) } /* Try any drive */ rctx.any_drive = true; - Dmsg6(dbglvl, "jid=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", - (int)rctx.jcr->JobId, + Dmsg5(dbglvl, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); if ((ok = find_suitable_device_for_job(jcr, rctx))) { @@ -746,10 +736,9 @@ static bool use_storage_cmd(JCR *jcr) */ if (repeat++ > 1) { /* try algorithm 3 times */ bmicrosleep(30, 0); /* wait a bit */ - Dmsg1(dbglvl, "jid=%u repeat reserve algorithm\n", (int)rctx.jcr->JobId); + Dmsg0(dbglvl, "repeat reserve algorithm\n"); } else if (!rctx.suitable_device || !wait_for_device(jcr, wait_for_device_retries)) { - Dmsg1(dbglvl, "jid=%u Fail. !suitable_device || !wait_for_device\n", - (int)rctx.jcr->JobId); + Dmsg0(dbglvl, "Fail. !suitable_device || !wait_for_device\n"); fail = true; } lock_reservations(); @@ -770,14 +759,14 @@ static bool use_storage_cmd(JCR *jcr) dev_name.c_str(), media_type.c_str()); dir->fsend(NO_device, dev_name.c_str()); - Dmsg2(dbglvl, "jid=%u >dird: %s", jid(), dir->msg); + Dmsg1(dbglvl, ">dird: %s", dir->msg); } } else { unbash_spaces(dir->msg); pm_strcpy(jcr->errmsg, dir->msg); Jmsg(jcr, M_FATAL, 0, _("Failed command: %s\n"), jcr->errmsg); dir->fsend(BAD_use, jcr->errmsg); - Dmsg2(dbglvl, "jid=%u >dird: %s", jid(), dir->msg); + Dmsg1(dbglvl, ">dird: %s", dir->msg); } release_reserve_messages(jcr); @@ -798,12 +787,10 @@ static bool is_vol_in_autochanger(RCTX &rctx, VOLRES *vol) /* Find resource, and make sure we were able to open it */ if (strcmp(rctx.device_name, changer->hdr.name) == 0) { - Dmsg2(dbglvl, "jid=%u Found changer device %s\n", - (int)rctx.jcr->JobId, vol->dev->device->hdr.name); + Dmsg1(dbglvl, "Found changer device %s\n", vol->dev->device->hdr.name); return true; } - Dmsg2(dbglvl, "jid=%u Incorrect changer device %s\n", - (int)rctx.jcr->JobId, changer->hdr.name); + Dmsg1(dbglvl, "Incorrect changer device %s\n", changer->hdr.name); return false; } @@ -823,8 +810,7 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) } else { dirstore = jcr->read_store; } - Dmsg5(dbglvl, "jid=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d\n", - (int)rctx.jcr->JobId, + Dmsg4(dbglvl, "PrefMnt=%d exact=%d suitable=%d chgronly=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only); @@ -838,7 +824,7 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) dlist *temp_vol_list, *save_vol_list; VOLRES *vol = NULL; lock_volumes(); - Dmsg1(dbglvl, "jid=%u lock volumes\n", (uint32_t)rctx.jcr->JobId); + Dmsg0(dbglvl, "lock volumes\n"); /* * Create a temporary copy of the volume list. We do this, @@ -849,7 +835,7 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) * we can take note and act accordingly (probably redo the * search at least a few times). */ - Dmsg1(dbglvl, "jid=%u duplicate vol list\n", (int)rctx.jcr->JobId); + Dmsg0(dbglvl, "duplicate vol list\n"); temp_vol_list = New(dlist(vol, &vol->link)); foreach_dlist(vol, vol_list) { VOLRES *nvol; @@ -865,14 +851,14 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) Jmsg(jcr, M_WARNING, 0, "Logic error. Duplicating vol list hit duplicate.\n"); } } - Dmsg1(dbglvl, "jid=%u unlock volumes\n", (uint32_t)jcr->JobId); + Dmsg0(dbglvl, "unlock volumes\n"); unlock_volumes(); /* Look through reserved volumes for one we can use */ - Dmsg1(dbglvl, "jid=%u look for vol in vol list\n", (int)rctx.jcr->JobId); + Dmsg0(dbglvl, "look for vol in vol list\n"); foreach_dlist(vol, temp_vol_list) { if (!vol->dev) { - Dmsg2(dbglvl, "jid=%u vol=%s no dev\n", (int)rctx.jcr->JobId, vol->vol_name); + Dmsg1(dbglvl, "vol=%s no dev\n", vol->vol_name); continue; } /* Check with Director if this Volume is OK */ @@ -881,7 +867,7 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) continue; } - Dmsg2(dbglvl, "jid=%u vol=%s OK for this job\n", (int)rctx.jcr->JobId, vol->vol_name); + Dmsg1(dbglvl, "vol=%s OK for this job\n", vol->vol_name); foreach_alist(store, dirstore) { int stat; rctx.store = store; @@ -891,13 +877,12 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) rctx.device = vol->dev->device; if (vol->dev->is_autochanger()) { - Dmsg2(dbglvl, "jid=%u vol=%s is in changer\n", (int)rctx.jcr->JobId, - vol->vol_name); + Dmsg1(dbglvl, "vol=%s is in changer\n", vol->vol_name); if (!is_vol_in_autochanger(rctx, vol)) { continue; } } else if (strcmp(device_name, vol->dev->device->hdr.name) != 0) { - Dmsg3(dbglvl, "jid=%u device=%s not suitable want %s\n", (int)rctx.jcr->JobId, + Dmsg2(dbglvl, "device=%s not suitable want %s\n", vol->dev->device->hdr.name, device_name); continue; } @@ -905,20 +890,17 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) bstrncpy(rctx.VolumeName, vol->vol_name, sizeof(rctx.VolumeName)); rctx.have_volume = true; /* Try reserving this device and volume */ - Dmsg3(dbglvl, "jid=%u try vol=%s on device=%s\n", (int)rctx.jcr->JobId, - rctx.VolumeName, device_name); + Dmsg2(dbglvl, "try vol=%s on device=%s\n", rctx.VolumeName, device_name); stat = reserve_device(rctx); if (stat == 1) { /* found available device */ - Dmsg2(dbglvl, "jid=%u Suitable device found=%s\n", (int)rctx.jcr->JobId, - device_name); + Dmsg1(dbglvl, "Suitable device found=%s\n", device_name); ok = true; break; } else if (stat == 0) { /* device busy */ - Dmsg2(dbglvl, "jid=%u Suitable device=%s, busy: not use\n", - (int)rctx.jcr->JobId, device_name); + Dmsg1(dbglvl, "Suitable device=%s, busy: not use\n", device_name); } else { /* otherwise error */ - Dmsg1(dbglvl, "jid=%u No suitable device found.\n", (int)rctx.jcr->JobId); + Dmsg0(dbglvl, "No suitable device found.\n"); } rctx.have_volume = false; } @@ -931,19 +913,18 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) } } /* end for loop over reserved volumes */ - Dmsg1(dbglvl, "jid=%u lock volumes\n", (uint32_t)rctx.jcr->JobId); + Dmsg0(dbglvl, "lock volumes\n"); lock_volumes(); save_vol_list = vol_list; vol_list = temp_vol_list; free_volume_list(); /* release temp_vol_list */ vol_list = save_vol_list; - Dmsg1(dbglvl, "jid=%u deleted temp vol list\n", (int)rctx.jcr->JobId); - Dmsg1(dbglvl, "jid=%u lock volumes\n", (uint32_t)rctx.jcr->JobId); + Dmsg0(dbglvl, "deleted temp vol list\n"); + Dmsg0(dbglvl, "lock volumes\n"); unlock_volumes(); } if (ok) { - Dmsg2(dbglvl, "jid=%u got vol %s from in-use vols list\n", (int)rctx.jcr->JobId, - rctx.VolumeName); + Dmsg1(dbglvl, "got vol %s from in-use vols list\n", rctx.VolumeName); return true; } @@ -960,16 +941,14 @@ bool find_suitable_device_for_job(JCR *jcr, RCTX &rctx) rctx.device_name = device_name; stat = search_res_for_device(rctx); if (stat == 1) { /* found available device */ - Dmsg2(dbglvl, "jid=%u available device found=%s\n", (int)rctx.jcr->JobId, - device_name); + Dmsg1(dbglvl, "available device found=%s\n", device_name); ok = true; break; } else if (stat == 0) { /* device busy */ - Dmsg2(dbglvl, "jid=%u Suitable device=%s, busy: not use\n", - (int)rctx.jcr->JobId, device_name); + Dmsg1(dbglvl, "Suitable device=%s, busy: not use\n", device_name); } else { /* otherwise error */ - Dmsg1(dbglvl, "jid=%u No suitable device found.\n", (int)rctx.jcr->JobId); + Dmsg0(dbglvl, "No suitable device found.\n"); } } if (ok) { @@ -988,29 +967,26 @@ int search_res_for_device(RCTX &rctx) AUTOCHANGER *changer; int stat; - Dmsg2(dbglvl, "jid=%u search res for %s\n", (int)rctx.jcr->JobId, rctx.device_name); + Dmsg1(dbglvl, "search res for %s\n", rctx.device_name); /* Look through Autochangers first */ foreach_res(changer, R_AUTOCHANGER) { - Dmsg2(dbglvl, "jid=%u Try match changer res=%s\n", (int)rctx.jcr->JobId, changer->hdr.name); + Dmsg1(dbglvl, "Try match changer res=%s\n", changer->hdr.name); /* Find resource, and make sure we were able to open it */ if (strcmp(rctx.device_name, changer->hdr.name) == 0) { /* Try each device in this AutoChanger */ foreach_alist(rctx.device, changer->device) { - Dmsg2(dbglvl, "jid=%u Try changer device %s\n", (int)rctx.jcr->JobId, - rctx.device->hdr.name); + Dmsg1(dbglvl, "Try changer device %s\n", rctx.device->hdr.name); stat = reserve_device(rctx); if (stat != 1) { /* try another device */ continue; } /* Debug code */ if (rctx.store->append == SD_APPEND) { - Dmsg3(dbglvl, "jid=%u Device %s reserved=%d for append.\n", - (int)rctx.jcr->JobId, rctx.device->hdr.name, - rctx.jcr->dcr->dev->reserved_device); + Dmsg2(dbglvl, "Device %s reserved=%d for append.\n", + rctx.device->hdr.name, rctx.jcr->dcr->dev->reserved_device); } else { - Dmsg3(dbglvl, "jid=%u Device %s reserved=%d for read.\n", - (int)rctx.jcr->JobId, rctx.device->hdr.name, - rctx.jcr->read_dcr->dev->reserved_device); + Dmsg2(dbglvl, "Device %s reserved=%d for read.\n", + rctx.device->hdr.name, rctx.jcr->read_dcr->dev->reserved_device); } return stat; } @@ -1020,7 +996,7 @@ int search_res_for_device(RCTX &rctx) /* Now if requested look through regular devices */ if (!rctx.autochanger_only) { foreach_res(rctx.device, R_DEVICE) { - Dmsg2(dbglvl, "jid=%u Try match res=%s\n", (int)rctx.jcr->JobId, rctx.device->hdr.name); + Dmsg1(dbglvl, "Try match res=%s\n", rctx.device->hdr.name); /* Find resource, and make sure we were able to open it */ if (strcmp(rctx.device_name, rctx.device->hdr.name) == 0) { stat = reserve_device(rctx); @@ -1029,13 +1005,11 @@ int search_res_for_device(RCTX &rctx) } /* Debug code */ if (rctx.store->append == SD_APPEND) { - Dmsg3(dbglvl, "jid=%u Device %s reserved=%d for append.\n", - (int)rctx.jcr->JobId, rctx.device->hdr.name, - rctx.jcr->dcr->dev->reserved_device); + Dmsg2(dbglvl, "Device %s reserved=%d for append.\n", + rctx.device->hdr.name, rctx.jcr->dcr->dev->reserved_device); } else { - Dmsg3(dbglvl, "jid=%u Device %s reserved=%d for read.\n", - (int)rctx.jcr->JobId, rctx.device->hdr.name, - rctx.jcr->read_dcr->dev->reserved_device); + Dmsg2(dbglvl, "Device %s reserved=%d for read.\n", + rctx.device->hdr.name, rctx.jcr->read_dcr->dev->reserved_device); } return stat; } @@ -1058,8 +1032,7 @@ static int reserve_device(RCTX &rctx) const int name_len = MAX_NAME_LENGTH; /* Make sure MediaType is OK */ - Dmsg3(dbglvl, "jid=%u chk MediaType device=%s request=%s\n", - (int)rctx.jcr->JobId, + Dmsg2(dbglvl, "chk MediaType device=%s request=%s\n", rctx.device->media_type, rctx.store->media_type); if (strcmp(rctx.device->media_type, rctx.store->media_type) != 0) { return -1; @@ -1083,7 +1056,7 @@ static int reserve_device(RCTX &rctx) } rctx.suitable_device = true; - Dmsg2(dbglvl, "jid=%u try reserve %s\n", rctx.jcr->JobId, rctx.device->hdr.name); + Dmsg1(dbglvl, "try reserve %s\n", rctx.device->hdr.name); rctx.jcr->dcr = dcr = new_dcr(rctx.jcr, rctx.jcr->dcr, rctx.device->dev); if (!dcr) { BSOCK *dir = rctx.jcr->dir_bsock; @@ -1096,26 +1069,24 @@ static int reserve_device(RCTX &rctx) bstrncpy(dcr->media_type, rctx.store->media_type, name_len); bstrncpy(dcr->dev_name, rctx.device_name, name_len); if (rctx.store->append == SD_APPEND) { - Dmsg3(dbglvl, "jid=%u have_vol=%d vol=%s\n", (int)rctx.jcr->JobId, - rctx.have_volume, rctx.VolumeName); + Dmsg2(dbglvl, "have_vol=%d vol=%s\n", rctx.have_volume, rctx.VolumeName); ok = reserve_device_for_append(dcr, rctx); if (!ok) { goto bail_out; } rctx.jcr->dcr = dcr; - Dmsg6(dbglvl, "jid=%u Reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n", - (int)rctx.jcr->JobId, + Dmsg5(dbglvl, "Reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n", dcr->dev->reserved_device, dcr->dev_name, dcr->media_type, dcr->pool_name, ok); if (!rctx.have_volume) { dcr->any_volume = true; if (dir_find_next_appendable_volume(dcr)) { bstrncpy(rctx.VolumeName, dcr->VolumeName, sizeof(rctx.VolumeName)); - Dmsg2(dbglvl, "jid=%u looking for Volume=%s\n", (int)rctx.jcr->JobId, rctx.VolumeName); + Dmsg1(dbglvl, "looking for Volume=%s\n", rctx.VolumeName); rctx.have_volume = true; } else { - Dmsg1(dbglvl, "jid=%u No next volume found\n", (int)rctx.jcr->JobId); + Dmsg0(dbglvl, "No next volume found\n"); rctx.have_volume = false; rctx.VolumeName[0] = 0; /* @@ -1155,8 +1126,7 @@ static int reserve_device(RCTX &rctx) ok = reserve_device_for_read(dcr); if (ok) { rctx.jcr->read_dcr = dcr; - Dmsg6(dbglvl, "jid=%u Read reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n", - (int)rctx.jcr->JobId, + Dmsg5(dbglvl, "Read reserved=%d dev_name=%s mediatype=%s pool=%s ok=%d\n", dcr->dev->reserved_device, dcr->dev_name, dcr->media_type, dcr->pool_name, ok); } @@ -1170,7 +1140,7 @@ static int reserve_device(RCTX &rctx) pm_strcpy(dev_name, rctx.device->hdr.name); bash_spaces(dev_name); ok = dir->fsend(OK_device, dev_name.c_str()); /* Return real device name */ - Dmsg2(dbglvl, "jid=%u >dird: %s", jid(), dir->msg); + Dmsg1(dbglvl, ">dird: %s", dir->msg); } else { ok = true; } @@ -1179,7 +1149,7 @@ static int reserve_device(RCTX &rctx) bail_out: rctx.have_volume = false; // free_dcr(dcr); - Dmsg1(dbglvl, "jid=%u Not OK.\n", (int)rctx.jcr->JobId); + Dmsg0(dbglvl, "Not OK.\n"); return 0; } @@ -1200,8 +1170,7 @@ static bool reserve_device_for_read(DCR *dcr) dev->dlock(); if (is_device_unmounted(dev)) { - Dmsg2(dbglvl, "jid=%u Device %s is BLOCKED due to user unmount.\n", - (int)jcr->JobId, dev->print_name()); + Dmsg1(dbglvl, "Device %s is BLOCKED due to user unmount.\n", dev->print_name()); Mmsg(jcr->errmsg, _("3601 JobId=%u device %s is BLOCKED due to user unmount.\n"), jcr->JobId, dev->print_name()); queue_reserve_message(jcr); @@ -1209,8 +1178,8 @@ static bool reserve_device_for_read(DCR *dcr) } if (dev->is_busy()) { - Dmsg5(dbglvl, "jid=%u Device %s is busy ST_READ=%d num_writers=%d reserved=%d.\n", - (int)jcr->JobId, dev->print_name(), + Dmsg4(dbglvl, "Device %s is busy ST_READ=%d num_writers=%d reserved=%d.\n", + dev->print_name(), dev->state & ST_READ?1:0, dev->num_writers, dev->reserved_device); Mmsg(jcr->errmsg, _("3602 JobId=%u device %s is busy (already reading/writing).\n"), jcr->JobId, dev->print_name()); @@ -1222,8 +1191,7 @@ static bool reserve_device_for_read(DCR *dcr) dev->set_read(); ok = true; dev->reserved_device++; - Dmsg4(dbglvl, "jid=%u Inc reserve=%d dev=%s %p\n", (int)jcr->JobId, - dev->reserved_device, dev->print_name(), dev); + Dmsg3(dbglvl, "Inc reserve=%d dev=%s %p\n", dev->reserved_device, dev->print_name(), dev); dcr->reserved_device = true; bail_out: @@ -1261,7 +1229,7 @@ static bool reserve_device_for_append(DCR *dcr, RCTX &rctx) if (dev->can_read()) { Mmsg(jcr->errmsg, _("3603 JobId=%u device %s is busy reading.\n"), jcr->JobId, dev->print_name()); - Dmsg2(dbglvl, "jid=%u %s", jid(), jcr->errmsg); + Dmsg1(dbglvl, "%s", jcr->errmsg); queue_reserve_message(jcr); goto bail_out; } @@ -1270,22 +1238,21 @@ static bool reserve_device_for_append(DCR *dcr, RCTX &rctx) if (is_device_unmounted(dev)) { Mmsg(jcr->errmsg, _("3604 JobId=%u device %s is BLOCKED due to user unmount.\n"), jcr->JobId, dev->print_name()); - Dmsg2(dbglvl, "jid=%u %s", jid(), jcr->errmsg); + Dmsg1(dbglvl, "%s", jcr->errmsg); queue_reserve_message(jcr); goto bail_out; } - Dmsg2(dbglvl, "jid=%u reserve_append device is %s\n", - (int)jcr->JobId, dev->print_name()); + Dmsg1(dbglvl, "reserve_append device is %s\n", dev->print_name()); /* Now do detailed tests ... */ if (can_reserve_drive(dcr, rctx) != 1) { - Dmsg1(dbglvl, "jid=%u can_reserve_drive!=1\n", (int)jcr->JobId); + Dmsg0(dbglvl, "can_reserve_drive!=1\n"); goto bail_out; } dev->reserved_device++; - Dmsg4(dbglvl, "jid=%u Inc reserve=%d dev=%s %p\n", (int)jcr->JobId, dev->reserved_device, + Dmsg3(dbglvl, "Inc reserve=%d dev=%s %p\n", dev->reserved_device, dev->print_name(), dev); dcr->reserved_device = true; ok = true; @@ -1304,8 +1271,7 @@ static int is_pool_ok(DCR *dcr) if (strcmp(dev->pool_name, dcr->pool_name) == 0 && strcmp(dev->pool_type, dcr->pool_type) == 0) { /* OK, compatible device */ - Dmsg2(dbglvl, "jid=%u OK dev: %s num_writers=0, reserved, pool matches\n", - jcr->JobId, dev->print_name()); + Dmsg1(dbglvl, "OK dev: %s num_writers=0, reserved, pool matches\n", dev->print_name()); return 1; } else { /* Drive Pool not suitable for us */ @@ -1314,8 +1280,8 @@ static int is_pool_ok(DCR *dcr) jcr->JobId, dcr->pool_name, dev->pool_name, dev->reserved_device, dev->print_name()); queue_reserve_message(jcr); - Dmsg3(dbglvl, "jid=%u failed: busy num_writers=0, reserved, pool=%s wanted=%s\n", - (int)jcr->JobId, dev->pool_name, dcr->pool_name); + Dmsg2(dbglvl, "failed: busy num_writers=0, reserved, pool=%s wanted=%s\n", + dev->pool_name, dcr->pool_name); } return 0; } @@ -1325,8 +1291,8 @@ static bool is_max_jobs_ok(DCR *dcr) DEVICE *dev = dcr->dev; JCR *jcr = dcr->jcr; - Dmsg5(dbglvl, "jid=%u MaxJobs=%d Jobs=%d reserves=%d Vol=%s\n", - (uint32_t)jcr->JobId, dcr->VolCatInfo.VolCatMaxJobs, + Dmsg4(dbglvl, "MaxJobs=%d Jobs=%d reserves=%d Vol=%s\n", + dcr->VolCatInfo.VolCatMaxJobs, dcr->VolCatInfo.VolCatJobs, dev->reserved_device, dcr->VolumeName); if (dcr->VolCatInfo.VolCatMaxJobs > 0 && dcr->VolCatInfo.VolCatMaxJobs <= @@ -1335,7 +1301,7 @@ static bool is_max_jobs_ok(DCR *dcr) Mmsg(jcr->errmsg, _("3610 JobId=%u Volume max jobs exceeded on drive %s.\n"), (uint32_t)jcr->JobId, dev->print_name()); queue_reserve_message(jcr); - Dmsg2(dbglvl, "jid=%u reserve dev failed: %s", (uint32_t)jcr->JobId, jcr->errmsg); + Dmsg1(dbglvl, "reserve dev failed: %s", jcr->errmsg); return false; /* wait */ } return true; @@ -1351,8 +1317,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) DEVICE *dev = dcr->dev; JCR *jcr = dcr->jcr; - Dmsg6(dbglvl, "jid=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", - (int)jcr->JobId, + Dmsg5(dbglvl, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); @@ -1365,8 +1330,8 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) * helps spread the load to the least used drives. */ if (rctx.try_low_use_drive && dev == rctx.low_use_drive) { - Dmsg3(dbglvl, "jid=%u OK dev=%s == low_drive=%s.\n", - jcr->JobId, dev->print_name(), rctx.low_use_drive->print_name()); + Dmsg2(dbglvl, "OK dev=%s == low_drive=%s.\n", + dev->print_name(), rctx.low_use_drive->print_name()); return 1; } /* If he wants a free drive, but this one is busy, no go */ @@ -1375,13 +1340,12 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) if ((dev->num_writers + dev->reserved_device) < rctx.num_writers) { rctx.num_writers = dev->num_writers + dev->reserved_device; rctx.low_use_drive = dev; - Dmsg3(dbglvl, "jid=%u set low use drive=%s num_writers=%d\n", - (int)jcr->JobId, dev->print_name(), rctx.num_writers); + Dmsg2(dbglvl, "set low use drive=%s num_writers=%d\n", + dev->print_name(), rctx.num_writers); } else { - Dmsg2(dbglvl, "jid=%u not low use num_writers=%d\n", - (int)jcr->JobId, dev->num_writers+dev->reserved_device); + Dmsg1(dbglvl, "not low use num_writers=%d\n", dev->num_writers+dev->reserved_device); } - Dmsg1(dbglvl, "jid=%u failed: !prefMnt && busy.\n", jcr->JobId); + Dmsg0(dbglvl, "failed: !prefMnt && busy.\n"); Mmsg(jcr->errmsg, _("3605 JobId=%u wants free drive but device %s is busy.\n"), jcr->JobId, dev->print_name()); queue_reserve_message(jcr); @@ -1393,7 +1357,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) Mmsg(jcr->errmsg, _("3606 JobId=%u prefers mounted drives, but drive %s has no Volume.\n"), jcr->JobId, dev->print_name()); queue_reserve_message(jcr); - Dmsg1(dbglvl, "jid=%u failed: want mounted -- no vol\n", (uint32_t)jcr->JobId); + Dmsg0(dbglvl, "failed: want mounted -- no vol\n"); return 0; /* No volume mounted */ } @@ -1403,12 +1367,11 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) */ if (rctx.exact_match && rctx.have_volume) { bool ok; - Dmsg6(dbglvl, "jid=%u PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", - (int)jcr->JobId, + Dmsg5(dbglvl, "PrefMnt=%d exact=%d suitable=%d chgronly=%d any=%d\n", rctx.PreferMountedVols, rctx.exact_match, rctx.suitable_device, rctx.autochanger_only, rctx.any_drive); - Dmsg5(dbglvl, "jid=%u have_vol=%d have=%s resvol=%s want=%s\n", - (int)jcr->JobId, rctx.have_volume, dev->VolHdr.VolumeName, + Dmsg4(dbglvl, "have_vol=%d have=%s resvol=%s want=%s\n", + rctx.have_volume, dev->VolHdr.VolumeName, dev->vol?dev->vol->vol_name:"*none*", rctx.VolumeName); ok = strcmp(dev->VolHdr.VolumeName, rctx.VolumeName) == 0 || (dev->vol && strcmp(dev->vol->vol_name, rctx.VolumeName) == 0); @@ -1417,9 +1380,8 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) jcr->JobId, rctx.VolumeName, dev->VolHdr.VolumeName, dev->print_name()); queue_reserve_message(jcr); - Dmsg4(dbglvl, "jid=%u not OK: dev have=%s resvol=%s want=%s\n", - (int)jcr->JobId, dev->VolHdr.VolumeName, - dev->vol?dev->vol->vol_name:"*none*", rctx.VolumeName); + Dmsg3(dbglvl, "not OK: dev have=%s resvol=%s want=%s\n", + dev->VolHdr.VolumeName, dev->vol?dev->vol->vol_name:"*none*", rctx.VolumeName); return 0; } if (is_volume_in_use(dcr)) { @@ -1432,8 +1394,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) if (rctx.autochanger_only && !dev->is_busy() && dev->VolHdr.VolumeName[0] == 0) { /* Device is available but not yet reserved, reserve it for us */ - Dmsg2(dbglvl, "jid=%u OK Res Unused autochanger %s.\n", - jcr->JobId, dev->print_name()); + Dmsg1(dbglvl, "OK Res Unused autochanger %s.\n", dev->print_name()); bstrncpy(dev->pool_name, dcr->pool_name, sizeof(dev->pool_name)); bstrncpy(dev->pool_type, dcr->pool_type, sizeof(dev->pool_type)); return 1; /* reserve drive */ @@ -1454,13 +1415,12 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) return 1; } else { /* Changing pool, unload old tape if any in drive */ - Dmsg1(dbglvl, "jid=%u OK dev: num_writers=0, not reserved, pool change, unload changer\n", - (int)jcr->JobId); + Dmsg0(dbglvl, "OK dev: num_writers=0, not reserved, pool change, unload changer\n"); unload_autochanger(dcr, 0); } } /* Device is available but not yet reserved, reserve it for us */ - Dmsg2(dbglvl, "jid=%u OK Dev avail reserved %s\n", jcr->JobId, dev->print_name()); + Dmsg1(dbglvl, "OK Dev avail reserved %s\n", dev->print_name()); bstrncpy(dev->pool_name, dcr->pool_name, sizeof(dev->pool_name)); bstrncpy(dev->pool_type, dcr->pool_type, sizeof(dev->pool_type)); return 1; /* reserve drive */ @@ -1486,7 +1446,7 @@ static int can_reserve_drive(DCR *dcr, RCTX &rctx) Mmsg(jcr->errmsg, _("3911 JobId=%u failed reserve drive %s.\n"), jcr->JobId, dev->print_name()); queue_reserve_message(jcr); - Dmsg2(dbglvl, "jid=%u failed: No reserve %s\n", jcr->JobId, dev->print_name()); + Dmsg1(dbglvl, "failed: No reserve %s\n", dev->print_name()); return 0; } diff --git a/bacula/technotes-2.3 b/bacula/technotes-2.3 index ac6843319f..679a76929a 100644 --- a/bacula/technotes-2.3 +++ b/bacula/technotes-2.3 @@ -2,16 +2,23 @@ General: 30Sep07 +kes Save jcr in thread specific data (tsd) for each thread. +kes Make Dmsg() print JobId as -%u. +kes Make Jmsg, Emsg, and others automatically pickup the jobid + for the thread if it exists. +kes Remove old reservation debug jid code. +kes Remove get_jcr_from_tid() from OpenSSL and tls code. ebl Add an option that permit to specify spool size in job definition. (Applying patches/testing/spoolsize_per_job.patch). You must upgrade SD and DIR at the same time. 28Sep07 kes Fix race condition that drops final block written to volume. This happens in rare cases with multiple simultaneous jobs - when the Volume fills. + when the Volume fills. This fixes bug #964. May be related + to bug #935 and possibly #903. kes Eliminate more strerror() and replace with bstrerror(). -kes Remove BSD getopt and replace with unrestricted IBM version -kes Fix Win32 build. +kes Remove BSD getopt and replace with unrestricted IBM version. +kes Fix Win32 build for changed calling sequences. kes More tweaks to the mount volume routines to get everything right. Changed variable name from find to have_vol, which is much easier to understand. @@ -19,29 +26,32 @@ kes Enhance btimer debug code. 27Sep07 kes Fix FD->SD authorization failure, which was due to spurious wakeups from a pthread_cond_timedwait(). Simply check the - predicate before continuing. This fixes bug #953 + predicate before continuing. This fixes bug #953. kes Add const char where needed (more to do). Remove temp debug code. 26Sep07 -kes Setup SQLite busy handler before doing queries. +kes Setup SQLite busy handler before doing queries. Fixes bug #967. kes Don't overwrite error message in check_tables_version. + Fixes bug #966. kes Unlock batch insert tables with same calls used elsewhere. kes Allow starting 59 jobs a second. kes Make SD session key more random. -kes Add retry for SQLite opening db if it fails. +kes Add retry for SQLite opening db if it fails. Probably helps + for bug #967. kes Suppress extra error messages during batch insert failure. + Fixes bug #966. kes Add jcr to timer packets so if killed message can be sent to job. kes Add JobId to all Dmsg() output. kes Put some FD auth code on dbglvl rather than fixed. kes Return insert attributes error message in db msg buffer to avoid - false error messages. -kes Separate batch init error messages. + false error messages. Helps fix bug #966. +kes Separate batch init error messages. Probably helps fix bug #966. kes Make SD code that contructs attribute insert check string lengths more carefully. kes If Dir gets an error during inserting attributes, cancel SD. This reduces unnecessary error messages. 24Sep07 kes Correct search boolean for getting Volume info -ebl Cleanup batch code. +ebl Cleanup batch code. Probably fixes bug #965. kes Back out one small change to the reservation system (reserving a volume). kes Rework how a Volume is mounted. It is now much more intelligent and will always attempt to use any mounted volume if possible and reduces @@ -84,6 +94,8 @@ kes Implement restore callback that Dirk and I agreed on for bat restore. This fixes bug #928. Restore of backup of zero files fails. kes Fix SQL Catalog logging which broke with new db_escape_string calling sequence. + +Release Version 2.2.4 14Sep07 kes Fix bacula_cats.def for new db_escape_string(). kes Increase size of name string when FD making connection to SD. -- 2.39.5