Imagecleanup taking a long time/errors in bpdbm.log

[Evan]

Hey all,

I've noticed that my Imagecleanup has been taking a long time to complete in the last 24 hours. Normally it fires right off and is done in a few seconds. Now it is taking hours....

It looks like it is connecting to my clients ok, from the activity monitor. However I cranked up logging on the bpdbm.log file and it tells a different story. it looks like it is having some issues connecting, but I really dont know how to read this file. could someone help shed some light on this issue for me.

I ran this on my master server, NBU 7.0 on windows 2008 with deduplication. I think that it is something with the dedupe storage unit that is slowing this down. Any ideas?

Here is a selection of the log:

11:05:55.594 [3612.1796] <16> read_info_file: EXCHANGE_SOURCE corrupt: expected range 0-3 got -1

11:05:55.594 [3612.1796] <16> read_info_file: EXCHANGE_SOURCE corrupt: expected range 0-3 got -1

11:05:55.594 [3612.1796] <16> read_info_file: EXCHANGE_SOURCE corrupt: expected range 0-3 got -1

11:05:55.594 [3612.1796] <4> TZ: Send Timezone offset=18000

11:05:55.594 [3612.1796] <16> read_info_file: EXCHANGE_SOURCE corrupt: expected range 0-3 got -1

11:05:55.594 [3612.1796] <16> read_info_file: EXCHANGE_SOURCE corrupt: expected range 0-3 got -1

11:05:55.594 [3612.1796] <16> read_info_file: EXCHANGE_SOURCE corrupt: expected range 0-3 got -1

11:05:55.594 [3612.1796] <4> TZ: Send Timezone offset=18000

11:05:55.594 [3612.1796] <4> TZ: Send Timezone offset=18000

11:05:55.594 [3612.1796] <16> read_info_file: EXCHANGE_SOURCE corrupt: expected range 0-3 got -1

11:05:55.594 [3612.1796] <16> read_info_file: EXCHANGE_SOURCE corrupt: expected range 0-3 got -1

11:05:55.594 [3612.1796] <16> read_info_file: EXCHANGE_SOURCE corrupt: expected range 0-3 got -1

11:05:55.609 [3612.1796] <4> TZ: Send Timezone offset=18000

11:05:55.609 [3612.1796] <16> read_info_file: EXCHANGE_SOURCE corrupt: expected range 0-3 got -1

11:05:55.609 [3612.1796] <16> read_info_file: EXCHANGE_SOURCE corrupt: expected range 0-3 got -1

11:05:55.609 [3612.1796] <16> read_info_file: EXCHANGE_SOURCE corrupt: expected range 0-3 got -1

11:05:55.609 [3612.1796] <4> TZ: Send Timezone offset=18000

These have something to do with Exchange i guess?

11:05:55.609 [3612.1796] <2> process_request: request complete: exit status 0  ; query type: 178

11:07:40.085 [4668.4352] <2> logconnections: BPDBM ACCEPT FROM 127.0.0.1.49742 TO 127.0.0.1.13724

11:07:40.085 [4668.4352] <2> sync_db: deprecated query function: qtype 41, options 0

11:07:40.100 [4668.4352] <2> process_request: request complete: exit status 133 invalid request; query type: 41

11:08:30.135 [4704.4160] <2> logconnections: BPDBM ACCEPT FROM 192.168.60.90.49750 TO 192.168.60.90.13724

11:08:30.135 [4704.4160] <2> process_request: request complete: exit status 0  ; query type: 98

11:08:41.354 [3392.4980] <2> logconnections: BPDBM ACCEPT FROM 127.0.0.1.49769 TO 127.0.0.1.13724

11:08:41.354 [3392.4980] <2> process_request: request complete: exit status 0  ; query type: 91

11:12:39.011 [1504.1508] <2> logconnections: BPDBM ACCEPT FROM 127.0.0.1.49792 TO 127.0.0.1.13724

11:12:39.011 [1504.1508] <2> image_db: Q_IMAGE_CHANGELOG

11:12:39.043 [1504.1508] <2> process_request: request complete: exit status 0  ; query type: 282

11:12:39.152 [1532.1536] <2> logconnections: BPDBM ACCEPT FROM 127.0.0.1.49795 TO 127.0.0.1.13724

11:12:39.152 [1532.1536] <2> image_db: Q_IMAGE_CHANGELOG

11:12:39.199 [1532.1536] <2> process_request: request complete: exit status 0  ; query type: 282

11:12:39.308 [4800.600] <2> logconnections: BPDBM ACCEPT FROM 127.0.0.1.49798 TO 127.0.0.1.13724

11:12:39.308 [4800.600] <2> image_db: Q_IMAGE_CHANGELOG

11:12:39.355 [4800.600] <2> process_request: request complete: exit status 0  ; query type: 282

11:12:40.230 [4900.4196] <2> logconnections: BPDBM ACCEPT FROM 127.0.0.1.49829 TO 127.0.0.1.13724

11:12:40.246 [4900.4196] <2> sync_db: deprecated query function: qtype 41, options 0

11:12:40.246 [4900.4196] <2> process_request: request complete: exit status 133 invalid request; query type: 41

11:13:30.249 [868.1140] <2> logconnections: BPDBM ACCEPT FROM 192.168.60.90.49842 TO 192.168.60.90.13724

11:13:30.265 [868.1140] <2> process_request: request complete: exit status 0  ; query type: 98

11:13:41.531 [4376.4208] <2> logconnections: BPDBM ACCEPT FROM 127.0.0.1.49849 TO 127.0.0.1.13724

11:13:41.546 [4376.4208] <2> process_request: request complete: exit status 0  ; query type: 91

11:16:16.759 [2556.4448] <2> logconnections: BPDBM ACCEPT FROM 127.0.0.1.49871 TO 127.0.0.1.13724

11:16:16.759 [2556.4448] <2> retrieveLocalPatchVersion: Reading from C:\Program Files\Veritas\NetBackup\version.txt

11:16:16.759 [2556.4448] <2> parsePatchVersionString: parsing = >7.0

<

11:16:16.759 [2556.4448] <2> parsePatchVersionString: theRest = ><

11:16:16.759 [2556.4448] <2> class_db: Q_CLASS_NAMES

11:16:16.759 [2556.4448] <4> TZ: Send Timezone offset=18000

11:16:16.759 [2556.4448] <2> process_request: request complete: exit status 0  ; query type: 185

11:16:17.384 [1516.1508] <2> logconnections: BPDBM ACCEPT FROM 127.0.0.1.49874 TO 127.0.0.1.13724

Thanks!!

Evan

[RiaanBadenhorst]

Hi,

Is the cleanup actually finishing or is it getting stuck. Please check this doc and try and run it manually, might give you more of a clue as to what is happening.

(its from older version netbackup but should still be valid)

http://www.symantec.com/business/support/index?page=content&id=TECH10828