cancel
Showing results for 
Search instead for 
Did you mean: 

Lotus notes backup fails with erro 42.

skarve
Level 4
Certified
Hello All,
   I am stuck with a Lotus notes backup issue since 2 weeks now. I have already opened a case with symantec and they do not seem to know the answer as well.

Here is a description:

1. File level backup works fine.
2. Lotus notes paramters (notes.ini and nserver.exe) already configured on client host properties.
3. Notes backup fails with error 42. It also says connection reset by peer.
4. On bpbrm failed to get KEEP_ALIVE
5. on bpbkar "nblnagent main(): ERR - failed to load LN library: C:\Program files\IBM\Lotus\Domino\nnotes.dll: Errno: 193 (nnotes.dll)


Troubleshooting done: 
1. Have run user backup to check reverse lookup, works fine.
2. Checked hostname resolution works fine.
3. rebooted and reinstalled the client. reinstalled the patch 6.5.3



Config info:

1. Master: Solaris 10

2. Client : Windows 2003 x64
3. Lotus Domino 8 (32 bit)
4. NBU Version on master and client : 6.5.3

This is happening on two Lotus domino servers.

bpbkar log:

3:33:14.515 PM: [4700.4924] <2> Environment::_initialize_BE(): All DLEs initialized (01248260)!
3:33:14.515 PM: [4700.4924] <2> BEDS_DumpDLEInfo(): Device Name : C:
3:33:14.515 PM: [4700.4924] <2> BEDS_DumpDLEInfo(): Device Name : D:
3:33:14.515 PM: [4700.4924] <2> BEDS_DumpDLEInfo(): Device Name : Microsoft Terminal Services
3:33:14.515 PM: [4700.4924] <2> BEDS_DumpDLEInfo(): Device Name : Microsoft Windows Network
3:33:14.515 PM: [4700.4924] <2> BEDS_DumpDLEInfo(): Device Name : Web Client Network
3:33:14.515 PM: [4700.4924] <2> BEDS_DumpDLEInfo(): Device Name : Shadow?Copy?Components
3:33:14.515 PM: [4700.4924] <2> tar_backupt_tfi::create: TAR - Backup started at 7/17/2009 3:33:14 PM
3:33:14.515 PM: [4700.4924] <2> tar_base::V_vTarMsgW: INF - Inform when done
3:33:14.515 PM: [4700.4924] <2> dtcp_write: TCP - success: send socket (840), 23 of 23 bytes
3:33:14.515 PM: [4700.4924] <2> tar_base::V_vTarMsgW: INF - Echo keepalives
3:33:14.515 PM: [4700.4924] <2> dtcp_write: TCP - success: send socket (840), 22 of 22 bytes
3:33:14.515 PM: [4700.4924] <2> tar_base::V_vTarMsgW: INF - BACKUP START
3:33:14.515 PM: [4700.4924] <2> dtcp_write: TCP - success: send socket (840), 19 of 19 bytes
3:33:14.515 PM: [4700.4924] <2> tar_base::V_vTarMsgW: TRV - BACKUP 7/17/2009 3:33:14 PM SGKDHMCD01_BKP Lotus Test FULL
3:33:14.515 PM: [4700.4924] <2> dtcp_write: TCP - success: send socket (840), 66 of 66 bytes
3:33:14.562 PM: [4700.4924] <2> dtcp_read: TCP - success: recv socket (540), 14 of 14 bytes
3:33:14.562 PM: [4700.4924] <2> tar_backup::V_SetupProcessContinue: TAR - CONTINUE BACKUP received
3:33:14.562 PM: [4700.4924] <2> tar_backup_tfi::setupFileDirectives: TAR - Processing filename list
3:33:14.562 PM: [4700.4924] <2> dtcp_read: TCP - success: recv socket (540), 4 of 4 bytes
3:33:14.562 PM: [4700.4924] <2> dtcp_read: TCP - success: recv socket (540), 33 of 33 bytes
3:33:14.562 PM: [4700.4924] <2> tar_backup_tfi::setupFileDirectives: TAR - backup filename = C:\Program Files\IBM\Lotus\Domino
3:33:14.562 PM: [4700.4924] <2> dtcp_read: TCP - success: recv socket (540), 4 of 4 bytes
3:33:14.562 PM: [4700.4924] <2> dtcp_read: TCP - success: recv socket (540), 8 of 8 bytes
3:33:14.562 PM: [4700.4924] <4> tar_base::startKeepaliveThread: INF - keepalive thread started
3:33:14.562 PM: [4700.1508] <4> tar_base::keepaliveThread: INF - keepalive thread is active with an interval of 60 seconds
3:33:14.562 PM: [4700.1508] <4> tar_base::keepaliveThread: INF - sending keepalive
3:33:14.562 PM: [4700.1508] <2> dtcp_write: TCP - success: send socket (840), 1 of 1 bytes
3:33:14.577 PM: [4700.4924] <4> V_LNBackup_Init: INF - V_LNBackup_Init <Enter>
3:33:14.577 PM: [4700.4924] <4> UpdatePath(): INF - Path updated with Lotus Program Dir 'C:\Program Files\IBM\Lotus\Domino'
3:33:14.577 PM: [4700.4924] <2> NBLN_Initialize(): INF - <Enter>
3:33:14.577 PM: [4700.4924] <2> NBLN_Initialize(): INF - <Exit> Lotus Context Initialized
3:33:14.577 PM: [4700.4924] <4> NBLN_SetDebugLog(): INF - <Enter> Debug Log Path: 'BPBKAR'
3:33:14.577 PM: [4700.4924] <4> V_LNBackup_SetLotusInfo: INF - V_LNBackup_SetLotusInfo <Enter> INI_Path:C:\Program Files\IBM\Lotus\Domino
3:33:14.577 PM: [4700.4924] <4> NBLN_SetLotusInfo(): INF - <Enter> NotesIniPath:C:\Program Files\IBM\Lotus\Domino
3:33:14.577 PM: [4700.4924] <4> dos_backup::V_VerifyLotus: INF - Replaced: C:\Program Files\IBM\Lotus\Domino with Lotus Notes:\C:\Program Files\IBM\Lotus\Domino
3:33:14.577 PM: [4700.4924] <4> dos_backup::V_VerifyFileList: INF - UBS Local Type for 'Lotus Notes:\C:\Program Files\IBM\Lotus\Domino' --> 00120000
3:33:14.577 PM: [4700.4924] <4> NBLN_Connect(): INF - <Enter> NotesIniPath:'C:\Program Files\IBM\Lotus\Domino'
3:33:14.577 PM: [4700.4924] <4> NBLN_StartAgent(): INF - nblnagent debug log path: 'BPBKAR'
3:33:14.577 PM: [4700.4924] <4> NBLN_StartAgent(): INF - nblnagent command: '"C:\Program Files\Veritas\NetBackup\bin\nblnagent.exe" "C:\Program Files\Veritas\NetBackup\Logs\BPBKAR" 2'
3:33:14.577 PM: [2760.6648] <16> nblnagent main(): ERR - failed to load LN library: C:\Program Files\IBM\Lotus\Domino\nnotes.dll: Errno:193 (nnotes.dll)
3:33:14.577 PM: [2760.6648] <4> nblnagent LNAPI_stopServer(): INF - stopping nblnagent
3:33:14.577 PM: [2760.6648] <4> nblnagent LNAPI_stopServer(): INF - terminated normally
3:33:14.577 PM: [4700.4924] <16> getWORD(): ERR - ReadFile FAILED, Errno=109
3:33:14.577 PM: [4700.4924] <2> LN_stopClient(): INF - Stopping Client
3:33:14.577 PM: [4700.4924] <4> NBLN_Connect(): INF - Path to Notes.ini='=C:\Program Files\IBM\Lotus\Domino' passing to NotesInitExtended().
3:33:14.577 PM: [4700.4924] <16> NBLN_Connect(): ERR - NotesInitExtended() Failed (ErrorCode: 0xFFFF)
3:33:14.577 PM: [4700.4924] <4> Packer::open(): INF - Started Backup...
3:33:14.577 PM: [4700.4924] <4> Transporter::setThrottlingParameters(): INF - Throttling parameters set in Transporter
3:33:14.577 PM: [4700.4924] <4> backup_create: INF - NetBackup Temp Directory: 'C:\Program Files\Veritas\\NetBackup\Temp'
3:33:14.577 PM: [4700.4924] <2> tar_base::V_vTarMsgW: INF - Estimate:-1 -1
3:33:14.577 PM: [4700.4924] <2> dtcp_write: TCP - success: send socket (840), 21 of 21 bytes
3:33:14.577 PM: [4700.4924] <2> NBLN_GetTransLogStyle(): INF - <Enter>
3:33:14.577 PM: [4700.4924] <4> tar_base::V_vTarMsgW: INF - tar message received from dos_backup::tfs_startdir
3:33:14.577 PM: [4700.4924] <2> tar_base::V_vTarMsgW: TRV - object not found for file system backup: Lotus Notes:\C:\Program Files\IBM\Lotus\Domino
3:33:14.577 PM: [4700.4924] <2> dtcp_write: TCP - success: send socket (840), 94 of 94 bytes
3:33:14.577 PM: [4700.4924] <2> dtcp_write: TCP - success: send socket (840), 65 of 65 bytes
3:33:14.577 PM: [4700.4924] <4> tar_backup::backup_add_last_entry_state: INF - catalog message: Dfi - 0 0 0 -1 23 292 user other 0 0 0 0 /VRTS_IMAGE_SIZE_RECORD
3:33:14.577 PM: [4700.4924] <4> Packer::padBuffer(): INF - Padding (1024) bytes with pad value = (0x00000000).
3:33:14.593 PM: [4700.4924] <2> tar_base::backup_finish: TAR - backup: 0 files
3:33:14.593 PM: [4700.4924] <2> tar_base::backup_finish: TAR - backup: file data: 0 bytes
3:33:14.593 PM: [4700.4924] <2> tar_base::backup_finish: TAR - backup: image data: 1024 bytes
3:33:14.593 PM: [4700.4924] <2> tar_base::backup_finish: TAR - backup: elapsed time: 1 secs 1024 bps
3:33:14.609 PM: [4700.4924] <2> tar_base::V_vTarMsgW: INF - Total Size:0
3:33:14.609 PM: [4700.4924] <2> dtcp_write: TCP - success: send socket (840), 19 of 19 bytes
3:33:14.609 PM: [4700.4924] <4> tar_backup::backup_done_state: INF - number of file directives not found: 1
3:33:14.609 PM: [4700.4924] <4> tar_backup::backup_done_state: INF - number of file directives found: 0
3:33:14.609 PM: [4700.4924] <2> tar_base::V_vTarMsgW: INF - Client completed sending data for backup
3:33:14.609 PM: [4700.4924] <4> tar_base::stopKeepaliveThread: INF - waiting for keepalive thread to exit ...
3:33:14.609 PM: [4700.1508] <4> tar_base::keepaliveThread: INF - keepalive thread terminating (reason: WAIT_OBJECT_0)
3:33:14.609 PM: [4700.4924] <4> tar_base::stopKeepaliveThread: INF - keepalive thread has exited. (reason: WAIT_OBJECT_0)
3:33:14.609 PM: [4700.4924] <2> tar_base::V_vTarMsgW: INF - EXIT STATUS 71: none of the files in the file list exist



And here is the bpbrm log:



17:23:27.383 [8796] <2> bpbrm main: INITIATING (VERBOSE = 1): version NetBackup 6.5 2008103100

17:23:27.384 [8796] <2> logparams: -backup -S SGKDHBS101 -c SGKDHMCD01_BKP -ct 25 -ru root -cl Lotus_Test -sched T -bt 1247649806 -dt 0 -st 0 -b SGKDHMCD01_BK

P_1247649806 -mediasvr SGKDHBS101 -jobid 13779 -jobgrpid 13779 -masterversion 650000 -maxfrag 524288 -reqid -1247385615 -mt 0 -to 1966020 -stunit Disk_Test -r

l 1 -rp 1209600 -p /tmp/nbu_backups -mst 1 -flags 0 -use_ofb -use_otm -jm -secure 1 -kl 28 -rg root -fso -connect_options 16974338

17:23:27.389 [8796] <2> init_cache: vnet_hosts.c.990: host_cache_size: 200 0x000000c8

17:23:27.389 [8796] <2> init_cache: vnet_hosts.c.991: cache_time: 3600 0x00000e10

17:23:27.389 [8796] <2> init_cache: vnet_hosts.c.1003: host_failed_cache_size: 40 0x00000028

17:23:27.389 [8796] <2> init_cache: vnet_hosts.c.1004: cache_time: 3600 0x00000e10

17:23:27.390 [8796] <2> init_cache: vnet_hosts.c.990: host_cache_size: 200 0x000000c8

17:23:27.390 [8796] <2> init_cache: vnet_hosts.c.991: cache_time: 3600 0x00000e10

17:23:27.390 [8796] <2> init_cache: vnet_hosts.c.1003: host_failed_cache_size: 40 0x00000028

17:23:27.390 [8796] <2> init_cache: vnet_hosts.c.1004: cache_time: 3600 0x00000e10

17:23:27.404 [8796] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2043: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006

17:23:27.404 [8796] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2057: service: bpcd

17:23:27.485 [8796] <2> logconnections: BPCD CONNECT FROM 10.122.28.72.61770 TO 10.122.28.24.13724

17:23:27.487 [8796] <2> vnet_connect_to_vnetd_extra: vnet_vnetd.c.179: msg: VNETD CONNECT FROM 10.122.28.72.61771 TO 10.122.28.24.13724 fd = 8

17:23:27.499 [8796] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.532: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a

17:23:27.704 [8796] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.549: ipc_string: 4999

17:23:27.763 [8796] <2> bpbrm start_bpcd_stat: DATA_SOCK from bpcr = 7

17:23:27.763 [8796] <2> bpbrm start_bpcd_stat: NAME_SOCK from bpcr = 8

17:23:27.903 [8796] <2> bpbrm main: send_3_0_client_params = 1

17:23:27.903 [8796] <2> bpbrm main: backup_cmd = /usr/openv/netbackup/bin/bpbkar bpbkar -r 1209600 -ru root -dt 0 -to 1966020 -clnt SGKDHMCD01_BKP -class Lotu

s_Test -sched T -st FULL -bpstart_to 32767 -bpend_to 32767 -read_to 300 -blks_per_buffer 1024 -use_otm -fso -b SGKDHMCD01_BKP_1247649806 -kl 28 -ct 25

17:23:27.916 [8796] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2043: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006

17:23:27.916 [8796] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2057: service: bpcd

17:23:28.033 [8796] <2> logconnections: BPCD CONNECT FROM 10.122.28.72.61774 TO 10.122.28.24.13724

17:23:28.034 [8796] <2> vnet_connect_to_vnetd_extra: vnet_vnetd.c.179: msg: VNETD CONNECT FROM 10.122.28.72.61775 TO 10.122.28.24.13724 fd = 8

17:23:28.046 [8796] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.532: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a

17:23:28.250 [8796] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.549: ipc_string: 1027

17:23:28.303 [8796] <2> bpbrm start_bpcd_stat: DATA_SOCK from bpcr = 7

17:23:28.303 [8796] <2> bpbrm start_bpcd_stat: NAME_SOCK from bpcr = 8

17:23:28.438 [8796] <2> bpcr_get_version_rqst: bpcd version: 06530000

17:23:28.493 [8796] <2> bpcr_get_platform_rqst: Server client platform length = 7

17:23:28.493 [8796] <2> bpcr_check_for_use_ofb_support: bpcd platform win_x64

17:23:28.494 [8796] <2> bpbrm main: received bpcd success message

17:23:28.592 [8796] <2> get_readline_type: Returning BPBRM_READ_INFORM_WHEN_DONE

17:23:28.643 [8796] <2> bpbrm main: from client SGKDHMCD01_BKP: read client start message

17:23:28.643 [8796] <2> bpbrm spawn_child: /usr/openv/netbackup/bin/bptm bptm -w -c SGKDHMCD01_BKP -dpath /tmp/nbu_backups -stunit Disk_Test -cl Lotus_Test -b

t 1247649806 -b SGKDHMCD01_BKP_1247649806 -st 0 -cj 1 -reqid -1247385615 -jm -brm -hostname SGKDHMCD01_BKP -ru root -rclnt SGKDHMCD01_BKP -rclnthostname SGKDH

MCD01_BKP -rl 1 -rp 1209600 -sl T -ct 25 -maxfrag 524288 -v -mediasvr SGKDHBS101 -no_callback -connect_options 0x01010100 -jobid 13779 -jobgrpid 13779 -master

version 650000 -bpbrm_shm_id 150995028 -blks_per_buffer 1024

17:23:28.647 [8796] <2> bpbrm write_continue_backup: wrote CONTINUE BACKUP on COMM_SOCK <7>

17:23:28.648 [8796] <2> write_file_names: buffering file name 'd:\lotus\domino\data' for output

17:23:28.648 [8796] <2> write_file_names: successfully wrote buffer to COMM_SOCK

17:23:28.648 [8796] <2> bpbrm main: wrote CONTINUE on COMM_SOCK

17:23:28.650 [8796] <4> bpbrm main: from client SGKDHMCD01_BKP: TRV - BACKUP 7/15/2009 5:23:28 PM SGKDHMCD01_BKP Lotus_Test T FULL

17:23:28.651 [8796] <2> db_error_add_to_file: dberrorq.c:midnite = 1247587200

17:23:28.695 [8796] <2> bpbrm main: ESTIMATE -1 -1 SGKDHMCD01_BKP_1247649806

17:23:28.695 [8796] <4> bpbrm main: from client SGKDHMCD01_BKP: TRV - object not found for file system backup: Lotus Notes:\D:\lotus\domino\data

17:23:28.695 [8796] <2> db_error_add_to_file: dberrorq.c:midnite = 1247587200

17:23:28.709 [8796] <2> bpbrm main: client SGKDHMCD01_BKP EXIT STATUS = 71: none of the files in the file list exist

17:23:28.710 [8796] <2> bpbrm kill_child_process: start

17:23:28.710 [8796] <2> bpbrm wait_for_child: start

17:23:32.445 [8796] <2> bpbrm mm_sig: received ready signal from media manager

17:23:35.522 [8796] <2> bpbrm wait_for_child: child exit_status = 42 signal_status = 0

17:23:35.522 [8796] <2> inform_client_of_status: INF - Server status = 42

17:23:35.523 [8796] <2> put_long: (11) network write() error: Broken pipe (32); socket = 7

17:23:35.523 [8796] <16> inform_client_of_status: could not send server status message

17:23:35.576 [8796] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2043: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006

17:23:35.577 [8796] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2057: service: bpjobd

17:23:35.579 [8796] <2> job_connect: SO_KEEPALIVE set on socket 9 for client SGKDHBS101

17:23:35.579 [8796] <2> logconnections: BPJOBD CONNECT FROM 10.122.28.72.61855 TO 10.122.28.72.13724

17:23:35.579 [8796] <2> job_authenticate_connection: ignoring VxSS authentication check for now...

17:23:35.580 [8796] <2> job_connect: Connected to the host SGKDHBS101 contype 10 jobid <13779> socket <9>

17:23:35.580 [8796] <2> job_connect: Connected on port 61855

17:23:35.582 [8796] <2> job_monitoring_exex: ACK disconnect

17:23:35.582 [8796] <2> job_disconnect: Disconnected

17:23:35.582 [8796] <2> db_error_add_to_file: dberrorq.c:midnite = 1247587200

17:23:35.600 [8796] <2> inform_client_of_status: Could not set linger value on socket. Errno = 22: Invalid argument

17:23:35.600 [8796] <2> bpbrm Exit: attempting to send mail to root on SGKDHMCD01_BKP

17:23:35.613 [8796] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2043: VN_REQUEST_SERVICE_SOCKET: 6 0x00000006

17:23:35.613 [8796] <2> vnet_vnetd_service_socket: vnet_vnetd.c.2057: service: bpcd

17:23:35.798 [8796] <2> logconnections: BPCD CONNECT FROM 10.122.28.72.61856 TO 10.122.28.24.13724

17:23:35.799 [8796] <2> vnet_connect_to_vnetd_extra: vnet_vnetd.c.179: msg: VNETD CONNECT FROM 10.122.28.72.61860 TO 10.122.28.24.13724 fd = 9

17:23:35.811 [8796] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.532: VN_REQUEST_CONNECT_FORWARD_SOCKET: 10 0x0000000a

17:23:36.019 [8796] <2> vnet_vnetd_connect_forward_socket_begin: vnet_vnetd.c.549: ipc_string: 1040

17:23:36.073 [8796] <2> bpbrm Exit: OUT_SOCK from bpcr = 7

17:23:36.073 [8796] <2> bpbrm Exit: IN_SOCK from bpcr = 9

17:23:36.141 [8796] <2> bpcr_get_version_rqst: bpcd version: 06530000

17:23:36.193 [8796] <2> bpcr_get_version_rqst: bpcd version: 06530000

17:23:36.313 [8796] <2> bpcr_get_version_rqst: bpcd version: 06530000

17:23:36.374 [8796] <2> bpbrm Exit: client backup EXIT STATUS 42: network read failed



Any help would be appreciated!!

Thanks
Sumeet








4 REPLIES 4

Anton_Panyushki
Level 6
Certified
Hello,


Ok, Try to increase BACKUP_TIMEOUT value in notes.ini file on that Domino server.
At least tweak this parameter up to 1800 seconds.
Ideally this parameter should match with "backup read timeout" of the media server(s) that is (are) used for the Lotus backup.

Raghuraam
Level 4
This happens when one of the node's duplex settings are different. or your network may not allow to communicate with that type of settings. Some times could be Master or client. Please check and do the needfull.

Or another reason could be because client may busy some times.

Raghuraam

Anton_Panyushki
Level 6
Certified
I think it is Domino problem , since file backup works ok.

skarve
Level 4
Certified
 Hi Anton,
      Well I would have loved to blame it on domino... :) but unfortunately I dont see any symptoms....even on the Client's event viewer. Any clue on how I can check on the domino side?