Amanda log files/Trace Logs

Each dump or flush creates a file named log.YYYYMMDDHHMMSS.N (or, if usetimestamps is off, log.YYYYMMDD.N) in the logdir directory, where YYYYMMDDHHMMSS is the timestamp of the start of the amdump/amflush run, and N is a sequence number starting at 0. These log files represent the Amanda catalog -- the database describing the contents of storage volumes (tapes). They are used for generating backup reports with amreport, tracking dumps with amadmin - find, and finding the required tapes for restore operations.

Do not delete these log files! Removing them means you cannot use Amanda tools to locate older backups (the information to restore the most recent backup is kept in the curinfo database, and is read by "amadmin xx info").

File Creation

During a run, the various components of Amanda write lines to $logdir/log. The presence of this file indicates that an Amanda application is running (really, that Amanda is using a device), and will cause most applications to suggest that the user run amcleanup. When a run is complete, amlogroll renames log to the full filename, pulling the datestamp from the file itself and using the zero-based sequence number to disambiguate logfiles with the same datestamp.

At the end of a run, amdump calls amtrmlog to move logfiles for runs whose tapes have been reused into a subdirectory named oldlog inside the logdir directory. It is up to the administrator to remove older log files from the oldlog subdirectory.

File Format

Each line in the file begins with a keyword and a program name, followed by keyword/program-specific text. The following description is organized by program, and then by keyword. It is not complete, and is based on a possibly-incorrect reading of the current Amanda source.

(general)

INFO pid/pid-done

INFO app procname pid pid
INFO app pid-done pid

Lines of this form indicate the start and normal shutdown, respectively, of an Amanda process. They are used by Amanda::Process and amcleanup(8) to be sure that all processes associated with an Amanda run are killed.

INFO/WARNING

In general, INFO and WARNING lines are not programmatically interpreted, but are displayed to the user directly by amreport (with the exception of the pid logs, described above).

taper

START

START taper timestamp label label tape t

This message indicates that the taper is starting a new tape. The first occurrence of this message will have t equal to 1, and t will count up from there. The timestamp will always match the timestamp of the logfile.

PART

PART taper label filenum hostname diskname dump_timestamp partnum/nparts level [sec secs kb kb kps kps]

This indicates that the taper has written a file, filenum, to volume label. The file contains a part (perhaps the only part) of the dump identified by hostname, diskname, dump_timestamp, and level, where dump_timestamp is the timestamp of the run in which the client dump took place, and may not be the same as the timestamp of the logfile. If nparts is not known, it is given as -1.

PARTPARTIAL

PARTPARTIAL taper label filenum hostname diskname dump_timestamp partnum/nparts level [sec secs kb kb kps kps] "message"

Similar to PART, but for split parts that are not completely written to the volume. Note that the taper does not report such split parts to the driver, but does add them to the logfile. If Amanda does not manage to write the entire split part to tape, then this partial split part may contain critical user data, so it should not be forgotten!

DONE

DONE taper hostname diskname dump_timestamp nparts level [sec secs kb kb kps kps]

This indicates that the taper has completely written the given dump to tape, and will only occur after all parts are written.

PARTIAL

PARTIAL taper hostname diskname dump_timestamp nparts level [sec secs kb kb kps kps] "message"

This indicates that the taper has written at least a file header to the volume, but encountered an error before finishing the dump. The format is identical to DONE, with the addition of a quoted error message at the end. nparts is the part number during which the failure occurred (so, for example, if one whole part was written, and then the taper ran out of space during the second part, nparts would be 2). The message is omitted when the taper writes an incomplete dumpfile without error (when the driver replies to DUMPER_STATUS with FAILED). Like the PARTIAL command in the Driver-Taper protocol, the statistics section of this command does not include any failed parts (although note that, in Amanda-2.6.1 and earlier, some failed parts were included). Thus, nparts will always be 1 or more, but kb and secs may be zero if an error occurred before any data was written.

FAIL

FAIL taper hostname diskname dump_timestamp level "message"

No data from the described dump was written to the volume. This is similar to PARTIAL, except that PARTIAL is used when some (but not all) data was written.

INFO / WARNING

INFO taper tape label kb kb fm num_files [OK]

this line is not interpreted by Amanda, but is familiar to users from amreport. It summarizes the usage of the volume with label label. The kb includes only successful parts (not PARTPARTIAL), but the num_files includes all files written to tape, partial or complete. The [OK] is always presend and thus meaningless.

INFO taper Will request retry of failed split part.

This is added to the log when writing a split part fails but can be re-started on the next volume.

INFO taper Will write new label `label' to new tape

This summarizes the result of a taper scan. Note that this line is added to the logfile before the driver has a chance to refuse permission to overwrite the tape.

ERROR

ERROR taper no-tape [reason]

This line displays reasons that the taper could not find a volume to write to (and thus failed). Note that the reason is not quoted in the usual Amanda fashion.

SUCCESS

SUCCESS taper client disk datestamp level [ sec time-took kb output-kb kp/s KB-per-second
      {wr: writers number of writes rdwait read wait time wrwait write wait time filemark filemark wait time}]

(all on one line) This message is no longer used by the taper, as of Amanda-2.6.0. It has a format similar to taper's DONE, but without nparts and including some extra stats specific to the shared-memory taper model.

Examples

Below are some examples of important messages with explanation in this log file.

• START taper datestamp datestamp label tape-label tape current-tape

START taper datestamp 20070305162948 label test-00 tape 0

This indicates that the taper started to write a tape.

• INFO taper tape tape label kb total tape used fm filemark [error or OK]

INFO taper tape test-00 kb 1472 fm 1 [OK]

This indicates that the taper has completed a tape and is writing and end marker.

• FINISH planner date datestamp time time elapsed since planner started.

FINISH planner date 20070305162948 time 0.294

This indicates that the planner has finished creating its plan, and dumping can begin.

• SUCCESS taper client disk datestamp level [ sec time-took kb output-kb kp/s KB-per-second {wr: writers number of writes rdwait read wait time wrwait write wait time filemark filemark wait time}]

SUCCESS taper localhost /tmp/quicktest/data 20070305162948 0 [sec 0.205 kb 1440 kps 7021.9 {wr: writers 46 rdwait 0.192 wrwait 0.011 filemark 0.0}]

This indicates that a dump has been successfully written to tape.

• SUCCESS dumper client disk timestamp level [sec total runtime kb size of dump kps kp per second orig-kb original size]

SUCCESS dumper localhost /tmp/quicktest/data 20070305162948 0 [sec 0.169 kb 1430 kps 8437.1 orig-kb 1430] 

This indicates that a dump has been successfully dumped (either to holding or directly to tape).