XP client backup never starts - bpbkar32 keeps going and going - Veritas Net Backup

This is a discussion on XP client backup never starts - bpbkar32 keeps going and going - Veritas Net Backup ; I recently added an XP SP 2 client to NetBackup Enterprise 5.0 as an addition to some Solaris and Windows 2000 clients. The 2000 and Solaris clients start backing up immediately when I fire off the backup process. There's no ...

+ Reply to Thread
Results 1 to 8 of 8

Thread: XP client backup never starts - bpbkar32 keeps going and going

  1. XP client backup never starts - bpbkar32 keeps going and going

    I recently added an XP SP 2 client to NetBackup Enterprise 5.0 as an
    addition to some Solaris and Windows 2000 clients. The 2000 and Solaris
    clients start backing up immediately when I fire off the backup process.
    There's no problem there. (I've also disabled any firewalls for
    testing with no difference.)

    The new XP system, however, fires off the bpbkar32 process, which just
    sits there and churns, churns, churns away. It doesn't freeze and as
    soon as I kill the backup, bpbkar32 goes away, so it is responsive to
    the server. It's not "freezing". But I could let it go for over 1/2
    hour just to back up a few thousands files and it still is doing nothing
    but taking up CPU cycles.

    The only thing that's really "unusual" about this is that it uses the
    nVidia nForce 4 chipset. The boot drive is a 160 GB IDE drive on its
    own, but the main data drive is a 160 GB SATA RAID+0. I don't know if
    this has anything to do with it or if this is just a function of how
    bpbkar32 reacts to Windows XP. Either way, it's very annoying when all
    of the other non-XP clients don't have this problem.

    I have tried the 5.0 client fresh of CD as well as the MP4 and MP5
    clients. Same thing.

    The system is an Athlon 64 3200+ w 1 GB RAM. (Obviously, this is not
    Windows XP 64-bit, just 32-bit.) So, it's by no means a slow system.
    Fearing that the install might have added the IA64 version, I manually
    reinstalled from the x86 directory. No dice there either.

    My guess is that it doesn't like the NVidia RAID software, but that's
    just a guess. If it's just reading files and their attributes, it
    shouldn't care about things like that, should it? Why would it care as
    long as it can get the NTFS information?I just wish that I knew what
    bpbkar32 was trying to do at the time. Hard drive access is sporradic,
    but not steady in any way. It also does this when I try to back up data
    on the C: drive, which is nothing more than a regular hard drive.

    Any suggestion on where to even start looking? Any settings that can
    be changed to tweak it?

  2. Re: XP client backup never starts - bpbkar32 keeps going and going

    in article 42756e4d@ROSASTDMZ05., John Berger at sorry.no.spam@allowed.com
    wrote on 5/1/05 3:49 PM:

    > I recently added an XP SP 2 client to NetBackup Enterprise 5.0 as an
    > addition to some Solaris and Windows 2000 clients. The 2000 and Solaris
    > clients start backing up immediately when I fire off the backup process.
    > There's no problem there. (I've also disabled any firewalls for
    > testing with no difference.)
    >
    > The new XP system, however, fires off the bpbkar32 process, which just
    > sits there and churns, churns, churns away. It doesn't freeze and as
    > soon as I kill the backup, bpbkar32 goes away, so it is responsive to
    > the server. It's not "freezing". But I could let it go for over 1/2
    > hour just to back up a few thousands files and it still is doing nothing
    > but taking up CPU cycles.
    >
    > The only thing that's really "unusual" about this is that it uses the
    > nVidia nForce 4 chipset. The boot drive is a 160 GB IDE drive on its
    > own, but the main data drive is a 160 GB SATA RAID+0. I don't know if
    > this has anything to do with it or if this is just a function of how
    > bpbkar32 reacts to Windows XP. Either way, it's very annoying when all
    > of the other non-XP clients don't have this problem.
    >
    > I have tried the 5.0 client fresh of CD as well as the MP4 and MP5
    > clients. Same thing.
    >
    > The system is an Athlon 64 3200+ w 1 GB RAM. (Obviously, this is not
    > Windows XP 64-bit, just 32-bit.) So, it's by no means a slow system.
    > Fearing that the install might have added the IA64 version, I manually
    > reinstalled from the x86 directory. No dice there either.
    >
    > My guess is that it doesn't like the NVidia RAID software, but that's
    > just a guess. If it's just reading files and their attributes, it
    > shouldn't care about things like that, should it? Why would it care as
    > long as it can get the NTFS information?I just wish that I knew what
    > bpbkar32 was trying to do at the time. Hard drive access is sporradic,
    > but not steady in any way. It also does this when I try to back up data
    > on the C: drive, which is nothing more than a regular hard drive.
    >
    > Any suggestion on where to even start looking? Any settings that can
    > be changed to tweak it?


    Log files would be a good start--what does the bpbkar log show?


  3. Re: XP client backup never starts - bpbkar32 keeps going and going

    ps wrote:

    > Log files would be a good start--what does the bpbkar log show?


    Fair enough. As you can see, I'm getting a number of getsockopt failures.
    I'm not sure how either the server or this particular client would be getting
    socket errors and messages about failing to receive messages. Again, I have both
    XP's firewall and Zone Alarm shut down. Nothing else inbound to the client
    is failing.

    The Netbackup Client Job Tracker shows when a job is started and when it's stopped,
    so I'm baffled that the logs claim that the client failed to receive a signal. I'm not
    having any other inbound or outbound TCP problems as far as I can tell. Also, when the
    backup process kicks in I notice that even my floppy A: drive quickly activates. Odd,
    since I'm not backing anything up from that.

    The client is up to date with all viable XP patches and I reinstalled NBU MP 5 to both
    the client and the server.

    Oh, I'm also using nVidia's on-board, gigabit Ethernet. That doesn't explain how the client
    gets every other connection (to start and stop) though.

    The C:\Windows\system32\drivers\etc\hosts file has the name of the NBU server defined
    in it. It is not listed in DNS. Additionally, I am the only user of this system; however,
    the client was installed to run as the system user.

    I have the client logging at maximum, so what you see is what you get.

    BPBKAR32's log
    --------------
    11:25:05.921 PM: [548.2688] <2> WinMain: DAT - standard input handle = 404
    11:25:05.937 PM: [548.2688] <2> WinMain: DAT - standard output handle = 1968
    11:25:05.937 PM: [548.2688] <2> WinMain: DAT - standard error handle = -1
    11:25:05.937 PM: [548.2688] <16> dtcp_getsocksize: TCP - getsockopt failure on SO_RCVBUF: (socket: -1) (TCP 10038: Socket operation
    on non-socket)
    11:25:05.937 PM: [548.2688] <16> dtcp_getsocksize: TCP - getsockopt failure on SO_SNDBUF: (socket: -1) (TCP 10038: Socket operation
    on non-socket)
    11:25:05.937 PM: [548.2688] <16> dtcp_setsocksize: TCP - setsockopt failure on SO_RCVBUF: (socket: -1) (requested size: 32768)
    (actual size: 0)(TCP 10038: Socket operation on non-socket)
    11:25:05.937 PM: [548.2688] <16> dtcp_setsocksize: TCP - setsockopt failure on SO_SNDBUF: (socket: -1) (requested size: 32768)
    (actual size: 0)(TCP 10038: Socket operation on non-socket)
    11:25:05.937 PM: [548.2688] <8> WinMain: WRN - Actual transfer buffer size, 0, does not equal requested size, 32768
    11:25:07.203 PM: [548.2688] <4> tar_backup::backup_create: INF - dwJobData: 00000000
    11:25:07.203 PM: [548.2688] <4> tar_backup::backup_create: INF - dwJob: 00000000
    11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - backup privileges enabled, previous = 0
    11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - restore privileges enabled, previous = 0
    11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - security privileges enabled, previous = 0
    11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - tcb privileges enabled, previous = 0
    11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - create token privileges enabled, previous = 0
    11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - user name: root
    11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - no access token: scheduled backup
    11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1) (TCP 10038: Socket operation on non-socket)
    11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send 6 bytes
    11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1) (TCP 10038: Socket operation on non-socket)
    11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send 17 bytes
    11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1) (TCP 10038: Socket operation on non-socket)
    11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send 6 bytes
    11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1) (TCP 10038: Socket operation on non-socket)
    11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send 16 bytes
    11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1) (TCP 10038: Socket operation on non-socket)
    11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send 6 bytes
    11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1) (TCP 10038: Socket operation on non-socket)
    11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send 13 bytes
    11:27:11.125 PM: [548.2688] <2> tar_base::V_vTarMsgW: ERR - CONTINUE BACKUP message not received
    11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1) (TCP 10038: Socket operation on non-socket)
    11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send 6 bytes
    11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1) (TCP 10038: Socket operation on non-socket)
    11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send 37 bytes
    11:27:11.125 PM: [548.2688] <4> backup_create: INF - NetBackup Temp Directory: 'C:\Program Files\VERITAS\\NetBackup\Temp'
    11:27:11.125 PM: [548.2688] <2> tar_base::V_vTarMsgW: INF - EXIT STATUS 66: client backup failed to receive the CONTINUE BACKUP message
    11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1) (TCP 10038: Socket operation on non-socket)
    11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send 6 bytes
    11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1) (TCP 10038: Socket operation on non-socket)
    11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send 76 bytes
    11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF -
    ================================================== ==============================
    11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF - Job Tracking Statistics
    11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF -
    --------------------------------------------------------------------------------
    11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF - Files: 0
    11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF - Folders: 0
    11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF - Bytes Data: 0
    11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF - Gigabytes Data: 0
    11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF - Bytes Image: 0
    11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF - Gigabytes Image: 0
    11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF -
    ================================================== ==============================
    11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF - Not waiting for server status
    11:27:11.125 PM: [548.2688] <4> OVStopCmd: INF - EXIT - status = 0
    11:27:11.125 PM: [548.2688] <16> dtcp_shutdown: TCP - failure: shutdown socket (-1) (TCP 10038: Socket operation on non-socket)
    11:27:11.125 PM: [548.2688] <16> dtcp_read: TCP - failure: recv socket (-1) (TCP 10038: Socket operation on non-socket)
    11:27:11.125 PM: [548.2688] <16> dtcp_close: TCP - failure: close (TCP 10038: Socket operation on non-socket)
    11:27:11.125 PM: [548.2688] <4> OVShutdown: INF - Finished process
    11:27:11.125 PM: [548.2688] <4> WinMain: INF - Exiting C:\Program Files\VERITAS\NetBackup\bin\bpbkar32.exe
    11:27:13.156 PM: [548.2688] <4> ov_log::OVClose: INF - Closing log file: C:\Program Files\VERITAS\NetBackup\logs\BPBKAR\050105.LOG

  4. Re: XP client backup never starts - bpbkar32 keeps going and going

    in article 4275b100@ROSASTDMZ05., John B at
    spammers-are-digital-terrorists@blah.com wrote on 5/1/05 8:36 PM:

    > ps wrote:
    >
    >> Log files would be a good start--what does the bpbkar log show?

    >
    > Fair enough. As you can see, I'm getting a number of getsockopt failures.
    > I'm not sure how either the server or this particular client would be getting
    > socket errors and messages about failing to receive messages. Again, I have
    > both
    > XP's firewall and Zone Alarm shut down. Nothing else inbound to the client
    > is failing.
    >
    > The Netbackup Client Job Tracker shows when a job is started and when it's
    > stopped,
    > so I'm baffled that the logs claim that the client failed to receive a signal.
    > I'm not
    > having any other inbound or outbound TCP problems as far as I can tell. Also,
    > when the
    > backup process kicks in I notice that even my floppy A: drive quickly
    > activates. Odd,
    > since I'm not backing anything up from that.
    >
    > The client is up to date with all viable XP patches and I reinstalled NBU MP 5
    > to both
    > the client and the server.
    >
    > Oh, I'm also using nVidia's on-board, gigabit Ethernet. That doesn't explain
    > how the client
    > gets every other connection (to start and stop) though.
    >
    > The C:\Windows\system32\drivers\etc\hosts file has the name of the NBU server
    > defined
    > in it. It is not listed in DNS. Additionally, I am the only user of this
    > system; however,
    > the client was installed to run as the system user.
    >
    > I have the client logging at maximum, so what you see is what you get.
    >
    > BPBKAR32's log
    > --------------
    > 11:25:05.921 PM: [548.2688] <2> WinMain: DAT - standard input handle = 404
    > 11:25:05.937 PM: [548.2688] <2> WinMain: DAT - standard output handle = 1968
    > 11:25:05.937 PM: [548.2688] <2> WinMain: DAT - standard error handle = -1
    > 11:25:05.937 PM: [548.2688] <16> dtcp_getsocksize: TCP - getsockopt failure on
    > SO_RCVBUF: (socket: -1) (TCP 10038: Socket operation
    > on non-socket)
    > 11:25:05.937 PM: [548.2688] <16> dtcp_getsocksize: TCP - getsockopt failure on
    > SO_SNDBUF: (socket: -1) (TCP 10038: Socket operation
    > on non-socket)
    > 11:25:05.937 PM: [548.2688] <16> dtcp_setsocksize: TCP - setsockopt failure on
    > SO_RCVBUF: (socket: -1) (requested size: 32768)
    > (actual size: 0)(TCP 10038: Socket operation on non-socket)
    > 11:25:05.937 PM: [548.2688] <16> dtcp_setsocksize: TCP - setsockopt failure on
    > SO_SNDBUF: (socket: -1) (requested size: 32768)
    > (actual size: 0)(TCP 10038: Socket operation on non-socket)
    > 11:25:05.937 PM: [548.2688] <8> WinMain: WRN - Actual transfer buffer size, 0,
    > does not equal requested size, 32768
    > 11:25:07.203 PM: [548.2688] <4> tar_backup::backup_create: INF - dwJobData:
    > 00000000
    > 11:25:07.203 PM: [548.2688] <4> tar_backup::backup_create: INF - dwJob:
    > 00000000
    > 11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - backup
    > privileges enabled, previous = 0
    > 11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - restore
    > privileges enabled, previous = 0
    > 11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - security
    > privileges enabled, previous = 0
    > 11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - tcb
    > privileges enabled, previous = 0
    > 11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - create
    > token privileges enabled, previous = 0
    > 11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - user name:
    > root
    > 11:25:07.203 PM: [548.2688] <4> dos_backup::V_PreProcessing: INF - no access
    > token: scheduled backup
    > 11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1)
    > (TCP 10038: Socket operation on non-socket)
    > 11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send
    > 6 bytes
    > 11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1)
    > (TCP 10038: Socket operation on non-socket)
    > 11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send
    > 17 bytes
    > 11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1)
    > (TCP 10038: Socket operation on non-socket)
    > 11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send
    > 6 bytes
    > 11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1)
    > (TCP 10038: Socket operation on non-socket)
    > 11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send
    > 16 bytes
    > 11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1)
    > (TCP 10038: Socket operation on non-socket)
    > 11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send
    > 6 bytes
    > 11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1)
    > (TCP 10038: Socket operation on non-socket)
    > 11:25:07.203 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send
    > 13 bytes
    > 11:27:11.125 PM: [548.2688] <2> tar_base::V_vTarMsgW: ERR - CONTINUE BACKUP
    > message not received
    > 11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1)
    > (TCP 10038: Socket operation on non-socket)
    > 11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send
    > 6 bytes
    > 11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1)
    > (TCP 10038: Socket operation on non-socket)
    > 11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send
    > 37 bytes
    > 11:27:11.125 PM: [548.2688] <4> backup_create: INF - NetBackup Temp Directory:
    > 'C:\Program Files\VERITAS\\NetBackup\Temp'
    > 11:27:11.125 PM: [548.2688] <2> tar_base::V_vTarMsgW: INF - EXIT STATUS 66:
    > client backup failed to receive the CONTINUE BACKUP message
    > 11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1)
    > (TCP 10038: Socket operation on non-socket)
    > 11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send
    > 6 bytes
    > 11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: send socket (-1)
    > (TCP 10038: Socket operation on non-socket)
    > 11:27:11.125 PM: [548.2688] <16> dtcp_write: TCP - failure: attempted to send
    > 76 bytes
    > 11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF -
    > ================================================== ============================
    > ==
    > 11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF - Job
    > Tracking Statistics
    > 11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF -
    > ------------------------------------------------------------------------------
    > --
    > 11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF -
    > Files: 0
    > 11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF -
    > Folders: 0
    > 11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF -
    > Bytes Data: 0
    > 11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF -
    > Gigabytes Data: 0
    > 11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF - Bytes
    > Image: 0
    > 11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF - Gigabytes
    > Image: 0
    > 11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF -
    > ================================================== ============================
    > ==
    > 11:27:11.125 PM: [548.2688] <4> tar_backup::backup_done_state: INF - Not
    > waiting for server status
    > 11:27:11.125 PM: [548.2688] <4> OVStopCmd: INF - EXIT - status = 0
    > 11:27:11.125 PM: [548.2688] <16> dtcp_shutdown: TCP - failure: shutdown socket
    > (-1) (TCP 10038: Socket operation on non-socket)
    > 11:27:11.125 PM: [548.2688] <16> dtcp_read: TCP - failure: recv socket (-1)
    > (TCP 10038: Socket operation on non-socket)
    > 11:27:11.125 PM: [548.2688] <16> dtcp_close: TCP - failure: close (TCP 10038:
    > Socket operation on non-socket)
    > 11:27:11.125 PM: [548.2688] <4> OVShutdown: INF - Finished process
    > 11:27:11.125 PM: [548.2688] <4> WinMain: INF - Exiting C:\Program
    > Files\VERITAS\NetBackup\bin\bpbkar32.exe
    > 11:27:13.156 PM: [548.2688] <4> ov_log::OVClose: INF - Closing log file:
    > C:\Program Files\VERITAS\NetBackup\logs\BPBKAR\050105.LOG



    Do the bpinetd logs show any netbackup or socket errors? Can you telnet to
    port 13782 on your machine from the netbackup server and/or other machines?
    Installing ethereal (http://www.ethereal.com/) on your client and watching
    packets go by during an attempted backup will also show you exactly what's
    going back and forth.


  5. Re: XP client backup never starts - bpbkar32 keeps going and going

    ps wrote:

    > Do the bpinetd logs show any netbackup or socket errors? Can you telnet to
    > port 13782 on your machine from the netbackup server and/or other machines?
    > Installing ethereal (http://www.ethereal.com/) on your client and watching
    > packets go by during an attempted backup will also show you exactly what's
    > going back and forth.


    They do show socket errors, but not during the time that I attempted to do
    a backup.

    I just went on the client and attempted to TELNET to itself on port 13872.
    Nothing responded. And last night where I could at least connect to the
    client through Host Properties --> Clients, I can no longer connect to it
    at all.

    I'm wondering if Zone Alarm really just fscked up the TCP/IP stack, which
    wouldn't be the first time. Either that or there is just something really
    flaky about my system that the NetBackup client just does not appreciate.

    7:17:47.687 AM: [400.520] <4> ov_log::OVLoop: Timestamp
    7:18:47.703 AM: [400.520] <4> ov_log::OVLoop: Timestamp
    7:19:47.718 AM: [400.520] <4> ov_log::OVLoop: Timestamp
    7:20:32.734 AM: [400.520] <4> WinMain: INF - Exiting main loop
    7:20:32.734 AM: [400.520] <4> V_ReplaceSystemRegistry: INF - the system
    hive does not need to be replaced
    7:20:32.765 AM: [400.520] <4> bpcd_destroy: INF - Destroying listen processes
    7:20:32.765 AM: [400.520] <4> bpcd_destroy: INF - Closing BPCD listen
    connection
    7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (linger):
    iErr=-1, optlen=4, onoff=0, linger=0
    7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (oob inline):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (keepalive):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (send
    timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (recv
    timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (debug):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (linger):
    iErr=-1, optlen=4, onoff=65444, linger=232
    7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (oob inline):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (keepalive):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (send
    timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (recv
    timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (debug):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.765 AM: [400.1784] <2> dtcp_accept: TCP - success: accept socket (-1)
    7:20:32.765 AM: [400.520] <2> dtcp_close: TCP - success: close socket (300)
    7:20:32.953 AM: [400.3888] <4> V_SpawnProcess: INF - accepted socket: -1
    7:20:32.953 AM: [400.520] <4> bpcd_destroy: INF - Closing VOPIED listen
    connection
    7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (linger):
    iErr=-1, optlen=4, onoff=524, linger=0
    7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (oob inline):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (keepalive):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (send
    timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (recv
    timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (debug):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (linger):
    iErr=-1, optlen=4, onoff=65444, linger=248
    7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (oob inline):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:33.000 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (keepalive):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:33.000 AM: [400.520] <2> dtcp_close: TCP - success: close socket (324)
    7:20:33.062 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (send
    timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:33.093 AM: [400.520] <4> bpcd_destroy: INF - Closing VNETD listen
    connection
    7:20:33.093 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (recv
    timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:33.093 AM: [400.3888] <4> V_SpawnProcess: INF - BPCD process started
    7:20:33.093 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (debug):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:33.093 AM: [400.3888] <16> dtcp_close: TCP - failure: close (TCP
    10038: Socket operation on non-socket)
    7:20:33.093 AM: [400.1788] <2> dtcp_accept: TCP - success: accept socket (-1)
    7:20:33.093 AM: [400.520] <2> dtcp_close: TCP - success: close socket (336)
    7:20:33.250 AM: [400.2788] <4> V_SpawnProcess: INF - accepted socket: -1
    7:20:33.250 AM: [400.520] <4> V_SpawnBPJAVA_TERM: INF- V_SpawnBPJAVA_TERM
    CloseHandle(BpjavaEventHandle) = 296
    7:20:33.250 AM: [400.520] <4> V_SSMConnect: INF - Able to create a named pipe
    7:20:33.375 AM: [400.2788] <4> V_SpawnProcess: INF - VOPIED process started
    7:20:33.375 AM: [400.2788] <16> dtcp_close: TCP - failure: close (TCP
    10038: Socket operation on non-socket)
    7:20:33.500 AM: [400.520] <4> WinMain: V_SSMTerminate successfully sent
    termination request to SSM.exe
    7:20:33.500 AM: [400.520] <4> WinMain: INF - Exiting
    C:\PROGRA~1\VERITAS\NETBAC~1\bin\bpinetd.exe
    7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (linger):
    iErr=-1, optlen=4, onoff=1048, linger=0
    7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (oob inline):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (keepalive):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (send
    timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (recv
    timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (debug):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (linger):
    iErr=-1, optlen=4, onoff=65444, linger=264
    7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (oob inline):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (keepalive):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (send
    timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (recv
    timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:34.562 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (debug):
    iErr=-1, optlen=4, optval=305419896 (0x12345678)
    7:20:34.562 AM: [400.1792] <2> dtcp_accept: TCP - success: accept socket (-1)
    7:20:35.250 AM: [400.2520] <4> V_SpawnProcess: INF - accepted socket: -1


  6. Re: XP client backup never starts - bpbkar32 keeps going and going

    in article 42761f68@ROSASTDMZ05., John B at
    spammers-are-digital-terrorists@blah.com wrote on 5/2/05 4:27 AM:

    > ps wrote:
    >
    >> Do the bpinetd logs show any netbackup or socket errors? Can you telnet to
    >> port 13782 on your machine from the netbackup server and/or other machines?
    >> Installing ethereal (http://www.ethereal.com/) on your client and watching
    >> packets go by during an attempted backup will also show you exactly what's
    >> going back and forth.

    >
    > They do show socket errors, but not during the time that I attempted to do
    > a backup.
    >
    > I just went on the client and attempted to TELNET to itself on port 13872.
    > Nothing responded. And last night where I could at least connect to the
    > client through Host Properties --> Clients, I can no longer connect to it
    > at all.
    >
    > I'm wondering if Zone Alarm really just fscked up the TCP/IP stack, which
    > wouldn't be the first time. Either that or there is just something really
    > flaky about my system that the NetBackup client just does not appreciate.
    >
    > 7:17:47.687 AM: [400.520] <4> ov_log::OVLoop: Timestamp
    > 7:18:47.703 AM: [400.520] <4> ov_log::OVLoop: Timestamp
    > 7:19:47.718 AM: [400.520] <4> ov_log::OVLoop: Timestamp
    > 7:20:32.734 AM: [400.520] <4> WinMain: INF - Exiting main loop
    > 7:20:32.734 AM: [400.520] <4> V_ReplaceSystemRegistry: INF - the system
    > hive does not need to be replaced
    > 7:20:32.765 AM: [400.520] <4> bpcd_destroy: INF - Destroying listen processes
    > 7:20:32.765 AM: [400.520] <4> bpcd_destroy: INF - Closing BPCD listen
    > connection
    > 7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (linger):
    > iErr=-1, optlen=4, onoff=0, linger=0
    > 7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (oob inline):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (keepalive):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (send
    > timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (recv
    > timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (debug):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (linger):
    > iErr=-1, optlen=4, onoff=65444, linger=232
    > 7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (oob inline):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (keepalive):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (send
    > timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (recv
    > timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.765 AM: [400.1784] <2> dtcp_showoptions: TCP - socket (debug):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.765 AM: [400.1784] <2> dtcp_accept: TCP - success: accept socket (-1)
    > 7:20:32.765 AM: [400.520] <2> dtcp_close: TCP - success: close socket (300)
    > 7:20:32.953 AM: [400.3888] <4> V_SpawnProcess: INF - accepted socket: -1
    > 7:20:32.953 AM: [400.520] <4> bpcd_destroy: INF - Closing VOPIED listen
    > connection
    > 7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (linger):
    > iErr=-1, optlen=4, onoff=524, linger=0
    > 7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (oob inline):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (keepalive):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (send
    > timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (recv
    > timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (debug):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (linger):
    > iErr=-1, optlen=4, onoff=65444, linger=248
    > 7:20:32.953 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (oob inline):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:33.000 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (keepalive):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:33.000 AM: [400.520] <2> dtcp_close: TCP - success: close socket (324)
    > 7:20:33.062 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (send
    > timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:33.093 AM: [400.520] <4> bpcd_destroy: INF - Closing VNETD listen
    > connection
    > 7:20:33.093 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (recv
    > timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:33.093 AM: [400.3888] <4> V_SpawnProcess: INF - BPCD process started
    > 7:20:33.093 AM: [400.1788] <2> dtcp_showoptions: TCP - socket (debug):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:33.093 AM: [400.3888] <16> dtcp_close: TCP - failure: close (TCP
    > 10038: Socket operation on non-socket)
    > 7:20:33.093 AM: [400.1788] <2> dtcp_accept: TCP - success: accept socket (-1)
    > 7:20:33.093 AM: [400.520] <2> dtcp_close: TCP - success: close socket (336)
    > 7:20:33.250 AM: [400.2788] <4> V_SpawnProcess: INF - accepted socket: -1
    > 7:20:33.250 AM: [400.520] <4> V_SpawnBPJAVA_TERM: INF- V_SpawnBPJAVA_TERM
    > CloseHandle(BpjavaEventHandle) = 296
    > 7:20:33.250 AM: [400.520] <4> V_SSMConnect: INF - Able to create a named pipe
    > 7:20:33.375 AM: [400.2788] <4> V_SpawnProcess: INF - VOPIED process started
    > 7:20:33.375 AM: [400.2788] <16> dtcp_close: TCP - failure: close (TCP
    > 10038: Socket operation on non-socket)
    > 7:20:33.500 AM: [400.520] <4> WinMain: V_SSMTerminate successfully sent
    > termination request to SSM.exe
    > 7:20:33.500 AM: [400.520] <4> WinMain: INF - Exiting
    > C:\PROGRA~1\VERITAS\NETBAC~1\bin\bpinetd.exe
    > 7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (linger):
    > iErr=-1, optlen=4, onoff=1048, linger=0
    > 7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (oob inline):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (keepalive):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (send
    > timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (recv
    > timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (debug):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (linger):
    > iErr=-1, optlen=4, onoff=65444, linger=264
    > 7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (oob inline):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (keepalive):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (send
    > timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:34.531 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (recv
    > timeout): iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:34.562 AM: [400.1792] <2> dtcp_showoptions: TCP - socket (debug):
    > iErr=-1, optlen=4, optval=305419896 (0x12345678)
    > 7:20:34.562 AM: [400.1792] <2> dtcp_accept: TCP - success: accept socket (-1)
    > 7:20:35.250 AM: [400.2520] <4> V_SpawnProcess: INF - accepted socket: -1
    >


    The fact that you can't connect to that port locally, and the socket errors
    in bpinet and bpbkar suggest to me that something is preventing NB from
    being able to listen on those ports. Odd though that other apps aren't
    having this poroblem--however are these other apps initiating outgoing
    connections as opposed to listening on incoming (as NB is). Could indeed be
    a fscked up zonealarm or SP2 firewall problem.


  7. Re: XP client backup never starts - bpbkar32 keeps going and going

    ps wrote:

    > The fact that you can't connect to that port locally, and the socket errors
    > in bpinet and bpbkar suggest to me that something is preventing NB from
    > being able to listen on those ports. Odd though that other apps aren't
    > having this poroblem--however are these other apps initiating outgoing
    > connections as opposed to listening on incoming (as NB is). Could indeed be
    > a fscked up zonealarm or SP2 firewall problem.


    Well, I got the one thing worked out. When I reinstalled the TCP/IP stack,
    it wiped out my static IP information and threw it to DNS. My bad.

    Now I'm back to what I had before - NetBackup is the ONLY process that will
    not work. Every other process that uses inbound traffic works fine; no
    problems whatsoever with outbound traffic for anything except NetBackup.
    If the TCP/IP stack really was hosed, I can't believe that it would only
    impact NetBackup. I've had my Winsock get corrupted to the point that NO
    traffic was allowed - in or out.

    I'm at a loss. The log files themselves state that where as some
    connections fail on their particular socket (TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)), other NBU processes
    handle their sockets without any problems (dtcp_close: TCP - success: close
    socket).

    I just can't see how this can be a Windows issue at this point. The NBU
    client is the ONLY thing that is being affected by this.

    Could something else be using those ports and refusing to let NBU take
    control of them? I have no idea what could be causing this other than a
    problem with the NBU client, but Veritas claims that this problem was fixed
    with maintenance pack 3.

    -- John



    11:19:47.265 PM: [1768.944] <4> tar_backup::OVRemoveLogs: INF - Purging log
    files from: C:\Program Files\VERITAS\NetBackup\logs\vopied
    11:19:47.265 PM: [1768.944] <4> dos_backup::V_PreProcessing: INF - backup
    privileges enabled, previous = 0
    11:19:47.265 PM: [1768.944] <4> dos_backup::V_PreProcessing: INF - restore
    privileges enabled, previous = 0
    11:19:47.265 PM: [1768.944] <4> dos_backup::V_PreProcessing: INF - security
    privileges enabled, previous = 0
    11:19:47.265 PM: [1768.944] <4> dos_backup::V_PreProcessing: INF - tcb
    privileges enabled, previous = 0
    11:19:47.265 PM: [1768.944] <4> dos_backup::V_PreProcessing: INF - create
    token privileges enabled, previous = 0
    11:19:47.265 PM: [1768.944] <4> dos_backup::V_PreProcessing: INF - user
    name: root
    11:19:47.265 PM: [1768.944] <4> dos_backup::V_PreProcessing: INF - no
    access token: scheduled backup
    11:19:47.265 PM: [1768.944] <2> tar_backup::backup_create: TAR - Backup
    started at 5/2/2005 11:19:47 PM
    11:19:47.265 PM: [1768.944] <2> tar_base::V_vTarMsgW: INF - Inform when done
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: attempted to
    send 6 bytes
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: attempted to
    send 17 bytes
    11:19:47.265 PM: [1768.944] <2> tar_base::V_vTarMsgW: INF - Echo keepalives
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: attempted to
    send 6 bytes
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: attempted to
    send 16 bytes
    11:19:47.265 PM: [1768.944] <2> tar_base::V_vTarMsgW: INF - BACKUP START
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: attempted to
    send 6 bytes
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: attempted to
    send 13 bytes
    11:19:47.265 PM: [1768.944] <2> tar_base::V_vTarMsgW: TRV - BACKUP 5/2/2005
    11:19:47 PM athlon3200 John_D_Drive Full FULL
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: attempted to
    send 6 bytes
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)
    11:19:47.265 PM: [1768.944] <16> dtcp_write: TCP - failure: attempted to
    send 63 bytes
    11:24:03.546 PM: [1768.944] <4> dtcp_read: TCP - info: recv socket (396),
    read 0 bytes
    11:24:03.546 PM: [1768.944] <4> tar_base::V_vTarMsgW: INF - tar message
    received from tar_backup::backup_create
    11:24:03.546 PM: [1768.944] <2> tar_base::V_vTarMsgW: ERR - CONTINUE BACKUP
    message not received
    11:24:03.546 PM: [1768.944] <16> dtcp_write: TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)
    11:24:03.546 PM: [1768.944] <16> dtcp_write: TCP - failure: attempted to
    send 6 bytes
    11:24:03.546 PM: [1768.944] <16> dtcp_write: TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)
    11:24:03.546 PM: [1768.944] <16> dtcp_write: TCP - failure: attempted to
    send 37 bytes
    11:24:03.546 PM: [1768.944] <4> backup_create: INF - NetBackup Temp
    Directory: 'C:\Program Files\VERITAS\\NetBackup\Temp'
    11:24:03.562 PM: [1768.944] <2> tar_base::V_vTarMsgW: INF - Client
    completed sending data for backup
    11:24:03.562 PM: [1768.944] <2> tar_base::V_vTarMsgW: INF - EXIT STATUS 66:
    client backup failed to receive the CONTINUE BACKUP message
    11:24:03.562 PM: [1768.944] <16> dtcp_write: TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)
    11:24:03.562 PM: [1768.944] <16> dtcp_write: TCP - failure: attempted to
    send 6 bytes
    11:24:03.562 PM: [1768.944] <16> dtcp_write: TCP - failure: send socket
    (-1) (TCP 10038: Socket operation on non-socket)
    11:24:03.562 PM: [1768.944] <16> dtcp_write: TCP - failure: attempted to
    send 76 bytes
    11:24:03.562 PM: [1768.944] <4> tar_backup::backup_done_state: INF - Not
    waiting for server status
    11:24:03.687 PM: [1768.944] <4> tar_backup::backup_done_state: INF - Backup
    finished at 5/2/2005 11:19:47 PM
    11:24:03.687 PM: [1768.944] <4> V_LNBackup_End: INF - V_LNBackup_End
    ExitStatus:1 Recycle Logs:0
    11:24:03.687 PM: [1768.944] <4> OVStopCmd: INF - EXIT - status = 0
    11:24:03.687 PM: [1768.944] <4> OVStopCmd: INF - Shutdown stderr connection
    11:24:03.687 PM: [1768.944] <16> dtcp_shutdown: TCP - failure: shutdown
    socket (-1) (TCP 10038: Socket operation on non-socket)
    11:24:03.687 PM: [1768.944] <4> OVStopCmd: INF - Shutdown stdout connection
    11:24:03.812 PM: [1768.944] <2> dtcp_shutdown: TCP - success: shutdown
    socket (1968)
    11:24:03.812 PM: [1768.944] <4> OVStopCmd: INF - Shutdown stdin connection
    11:24:03.812 PM: [1768.944] <2> dtcp_shutdown: TCP - success: shutdown
    socket (396)
    11:24:03.812 PM: [1768.944] <4> OVStopCmd: INF - Shutdown wait started
    11:24:03.812 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 2 C:\Documents and Settings\John\Local Settings\Application
    Data\Microsoft\Windows\UsrClass.dat
    HKEY_USERS\S-1-5-21-343818398-2052111302-839522115-1004_Classes
    11:24:03.812 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 4 C:\Documents and Settings\John\Local Settings\Application
    Data\Microsoft\Windows\UsrClass.dat.LOG
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 2 C:\Documents and Settings\John\NTUSER.DAT
    HKEY_USERS\S-1-5-21-343818398-2052111302-839522115-1004
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 4 C:\Documents and Settings\John\NTUSER.DAT.LOG
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 2 C:\Documents and Settings\LocalService\Local
    Settings\Application Data\Microsoft\Windows\UsrClass.dat
    HKEY_USERS\S-1-5-19_Classes
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 4 C:\Documents and Settings\LocalService\Local
    Settings\Application Data\Microsoft\Windows\UsrClass.dat.LOG
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 2 C:\Documents and Settings\LocalService\NTUSER.DAT
    HKEY_USERS\S-1-5-19
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 4 C:\Documents and Settings\LocalService\NTUSER.DAT.LOG
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 2 C:\Documents and Settings\NetworkService\Local
    Settings\Application Data\Microsoft\Windows\UsrClass.dat
    HKEY_USERS\S-1-5-20_Classes
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 4 C:\Documents and Settings\NetworkService\Local
    Settings\Application Data\Microsoft\Windows\UsrClass.dat.LOG
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 2 C:\Documents and Settings\NetworkService\NTUSER.DAT
    HKEY_USERS\S-1-5-20
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 4 C:\Documents and Settings\NetworkService\NTUSER.DAT.LOG
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 4 C:\pagefile.sys
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 1 C:\WINDOWS\system32\config\AppEvent.Evt Application
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 2 C:\WINDOWS\system32\config\default HKEY_USERS\.DEFAULT
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 4 C:\WINDOWS\system32\config\default.LOG
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 2 C:\WINDOWS\system32\config\SAM HKEY_LOCAL_MACHINE\SAM
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 4 C:\WINDOWS\system32\config\SAM.LOG
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 1 C:\WINDOWS\System32\config\SecEvent.Evt Security
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 2 C:\WINDOWS\system32\config\SECURITY HKEY_LOCAL_MACHINE\SECURITY
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 4 C:\WINDOWS\system32\config\SECURITY.LOG
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 2 C:\WINDOWS\system32\config\software HKEY_LOCAL_MACHINE\SOFTWARE
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 4 C:\WINDOWS\system32\config\software.LOG
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 1 C:\WINDOWS\system32\config\SysEvent.Evt System
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 2 C:\WINDOWS\system32\config\system HKEY_LOCAL_MACHINE\SYSTEM
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special File: 4 C:\WINDOWS\system32\config\system.LOG
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special Folder: 3 C:\ C
    11:24:03.921 PM: [1768.944] <4> dos_backup::OVDeInitSpecialInfo: INF -
    Special Folder: 3 D:\ D
    11:24:03.921 PM: [1768.944] <4> V_LNBackup_End: INF - V_LNBackup_End
    ExitStatus:1 Recycle Logs:0
    11:24:03.921 PM: [1768.944] <16> dtcp_read: TCP - failure: recv socket
    (396) (TCP 10058: Can't send after socket shutdown)
    11:24:03.921 PM: [1768.944] <16> dtcp_read: TCP - failure: recv socket (-1)
    (TCP 10038: Socket operation on non-socket)
    11:24:03.921 PM: [1768.944] <4> OVShutdown: INF - Shutdown wait finished
    11:24:03.921 PM: [1768.944] <4> OVShutdown: INF - Closing stderr connection
    11:24:03.921 PM: [1768.944] <16> dtcp_close: TCP - failure: close (TCP
    10038: Socket operation on non-socket)
    11:24:03.921 PM: [1768.944] <4> OVShutdown: INF - Closing stdout connection
    11:24:03.921 PM: [1768.944] <2> dtcp_close: TCP - success: close socket (1968)
    11:24:03.921 PM: [1768.944] <4> OVShutdown: INF - Closing stdin connection
    11:24:03.921 PM: [1768.944] <2> dtcp_close: TCP - success: close socket (396)
    11:24:03.921 PM: [1768.944] <4> OVShutdown: INF - Finished process
    11:24:03.937 PM: [1768.944] <4> WinMain: INF - Exiting C:\Program
    Files\VERITAS\NetBackup\bin\bpbkar32.exe
    11:24:06.031 PM: [1768.944] <4> ov_log::OVClose: INF - Closing log file:
    C:\Program Files\VERITAS\NetBackup\logs\BPBKAR\050205.LOG



  8. Re: XP client backup never starts - bpbkar32 keeps going and going

    ps wrote:

    > The fact that you can't connect to that port locally, and the socket errors
    > in bpinet and bpbkar suggest to me that something is preventing NB from
    > being able to listen on those ports. Odd though that other apps aren't
    > having this poroblem--however are these other apps initiating outgoing
    > connections as opposed to listening on incoming (as NB is). Could indeed be
    > a fscked up zonealarm or SP2 firewall problem.


    Well, here's something odd. If I open a DOS box and ping my Windows system
    from itself by name, I get the following:

    Reply from ::1: time<1ms
    Reply from ::1: time<1ms
    Reply from ::1: time<1ms
    Reply from ::1: time<1ms

    But if I do it by IP address, I get this:

    Pinging 192.168.1.45 with 32 bytes of data:

    Reply from 192.168.1.45: bytes=32 time<1ms TTL=128
    Reply from 192.168.1.45: bytes=32 time<1ms TTL=128
    Reply from 192.168.1.45: bytes=32 time<1ms TTL=128
    Reply from 192.168.1.45: bytes=32 time<1ms TTL=128

    Ping statistics for 192.168.1.45:
    Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
    Approximate round trip times in milli-seconds:
    Minimum = 0ms, Maximum = 0ms, Average = 0ms

    I did disable the IPv6 helper because (A) I don't need it and (B) I don't
    like how the IPv6 helper communicates with hotmail.com.

    Thoughts?

+ Reply to Thread