ANR2576W An attempt was made to update an event record for a scheduled operation which has already been executed

2003-02-18 Thread PAC Brion Arnaud 
Hi list !

Could someone help me with that one : I get a client node (win2k) for
which TSM reports following message every night :

02/18/03 03:29:01 ANR2576W An attempt was made to update an event record
for a scheduled operation which has already been executed - multiple
client schedulers may be active for node PAC2K340. 

I'm certain that no multiple schedulers are started on this node, but
from my analyse of the logs, I believe that, as soon as the node has
finished it's backup, the session hangs, due to network problem, and
when restarted becomes the same schedule again, and repeats the work.
Some logs, to make it clearer :

TSM activity log :

18.02.2003 00:32:06  ANR2561I Schedule prompter contacting PAC2K340
(session
  1369418) to start a scheduled operation.
18.02.2003 00:32:10  ANR0406I Session 1369423 started for node PAC2K340
(WinNT)
  (Tcp/Ip xxx.xxx.xxx.xxx(1401)).
18.02.2003 00:37:35  ANR0406I Session 1369771 started for node PAC2K340
(WinNT)
  (Tcp/Ip xxx.xxx.xxx.xxx(1405)).
18.02.2003 00:40:41  ANE4987E (Session: 1369771, Node: PAC2K340)  Error
  processing 'xx': the object is in use
  by another process

... skipped blah-blah

18.02.2003 01:03:14  ANR0482W Session 1369423 for node PAC2K340 (WinNT)
  terminated - idle for more than 15 minutes.
18.02.2003 01:13:47  ANR0406I Session 1371466 started for node PAC2K340
(WinNT)
  (Tcp/Ip xxx.xxx.xxx.xxx(1423)).
18.02.2003 01:29:12  ANR0482W Session 1371466 for node PAC2K340 (WinNT)
  terminated - idle for more than 15 minutes.
18.02.2003 01:32:54  ANR0406I Session 1372430 started for node PAC2K340
(WinNT)
  (Tcp/Ip xxx.xxx.xxx.xxx(1430)).
18.02.2003 01:48:50  ANE4952I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects inspected:   26,680
18.02.2003 01:48:50  ANE4954I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects backed up:2,255
18.02.2003 01:48:50  ANE4958I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects updated:  2
18.02.2003 01:48:50  ANE4960I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects rebound:  0
18.02.2003 01:48:50  ANE4957I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects deleted:  0
18.02.2003 01:48:50  ANE4970I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects expired:  1,207
18.02.2003 01:48:50  ANE4959I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects failed:  11
18.02.2003 01:48:50  ANE4961I (Session: 1372430, Node: PAC2K340)  Total
number
  of bytes transferred: 1.72 GB
18.02.2003 01:48:50  ANE4963I (Session: 1372430, Node: PAC2K340)  Data
transfer
  time:2,994.31 sec
18.02.2003 01:48:50  ANE4966I (Session: 1372430, Node: PAC2K340)
Network data
  transfer rate:  603.65 KB/sec
18.02.2003 01:48:50  ANE4967I (Session: 1372430, Node: PAC2K340)
Aggregate
  data transfer rate:392.95 KB/sec
18.02.2003 01:48:50  ANE4968I (Session: 1372430, Node: PAC2K340)
Objects
  compressed by:6%
18.02.2003 01:48:50  ANE4964I (Session: 1372430, Node: PAC2K340)
Elapsed
  processing time:00:03:39
18.02.2003 01:48:53  ANR0403I Session 1369771 ended for node PAC2K340
(WinNT).
18.02.2003 02:25:35  ANR0406I Session 1374418 started for node PAC2K340
(WinNT)
  (Tcp/Ip xxx.xxx.xxx.xxx(1083)).
18.02.2003 02:26:09  ANR0406I Session 1374443 started for node PAC2K340
(WinNT)
  (Tcp/Ip xxx.xxx.xxx.xxx(1101)).

...skipped blah-blah

18.02.2003 02:29:53  ANE4952I (Session: 1374418, Node: PAC2K340)  Total
number
  of objects inspected:   26,666
18.02.2003 02:29:53  ANE4954I (Session: 1374418, Node: PAC2K340)  Total
number
  of objects backed up:2,078
18.02.2003 02:29:53  ANE4958I (Session: 1374418, Node: PAC2K340)  Total
number
  of objects updated:  3
18.02.2003 02:29:53  ANE4960I (Session: 1374418, Node: PAC2K340)  Total
number
  of objects rebound:  0
18.02.2003 02:29:53  ANE4957I (Session: 1374418, Node: PAC2K340)  Total
number
  of objects deleted:  0
18.02.2003 02:29:53  ANE4970I (Session: 1374418, Node: PAC2K340)  Total
number
  of objects expired:  3
18.02.2003 02:29:53  ANE4959I (Session: 1374418, Node: PAC2K340)  Total
number
  of objects failed:   9
18.02.2003 02:29:53  ANE4961I (Session: 1374418, Node: PAC2K340)  Total
number
  of bytes transferred:   153.77 MB
18.02.2003 02:29:53

Re: ANR2576W An attempt was made to update an event record for a scheduled operation which has already been executed

2003-02-18 Thread Stapleton, Mark 
From: PAC Brion Arnaud [mailto:[EMAIL PROTECTED]] 
 Could someone help me with that one : I get a client node 
 (win2k) for which TSM reports following message every night :
 
 02/18/03 03:29:01 ANR2576W An attempt was made to update an 
 event record for a scheduled operation which has already been 
 executed - multiple client schedulers may be active for node 
 PAC2K340. 

Check to see if you have any restartable restores going on for the
client in question:

q restore

Cancel the session number if you do, and see if that makes the problem
go away.

--
Mark Stapleton ([EMAIL PROTECTED])

Re: ANR2576W An attempt was made to update an event record for a scheduled operation which has already been executed

2003-02-18 Thread Jon Evans 
I have seen this exact same problem. Running 5.1.1.0 server and 5.1.1.0
client. W2K platform.  I have had this problem for weeks and weeks

I could not figure it out either..

Presumably a bug??

-Original Message-
From: PAC Brion Arnaud [mailto:[EMAIL PROTECTED]] 
Sent: 18 February 2003 13:02
To: [EMAIL PROTECTED]
Subject: ANR2576W An attempt was made to update an event record for a
scheduled operation which has already been executed

Hi list !

Could someone help me with that one : I get a client node (win2k) for
which TSM reports following message every night :

02/18/03 03:29:01 ANR2576W An attempt was made to update an event record
for a scheduled operation which has already been executed - multiple
client schedulers may be active for node PAC2K340. 

I'm certain that no multiple schedulers are started on this node, but
from my analyse of the logs, I believe that, as soon as the node has
finished it's backup, the session hangs, due to network problem, and
when restarted becomes the same schedule again, and repeats the work.
Some logs, to make it clearer :

TSM activity log :

18.02.2003 00:32:06  ANR2561I Schedule prompter contacting PAC2K340
(session
  1369418) to start a scheduled operation.
18.02.2003 00:32:10  ANR0406I Session 1369423 started for node PAC2K340
(WinNT)
  (Tcp/Ip xxx.xxx.xxx.xxx(1401)).
18.02.2003 00:37:35  ANR0406I Session 1369771 started for node PAC2K340
(WinNT)
  (Tcp/Ip xxx.xxx.xxx.xxx(1405)).
18.02.2003 00:40:41  ANE4987E (Session: 1369771, Node: PAC2K340)  Error
  processing 'xx': the object is in use
  by another process

... skipped blah-blah

18.02.2003 01:03:14  ANR0482W Session 1369423 for node PAC2K340 (WinNT)
  terminated - idle for more than 15 minutes.
18.02.2003 01:13:47  ANR0406I Session 1371466 started for node PAC2K340
(WinNT)
  (Tcp/Ip xxx.xxx.xxx.xxx(1423)).
18.02.2003 01:29:12  ANR0482W Session 1371466 for node PAC2K340 (WinNT)
  terminated - idle for more than 15 minutes.
18.02.2003 01:32:54  ANR0406I Session 1372430 started for node PAC2K340
(WinNT)
  (Tcp/Ip xxx.xxx.xxx.xxx(1430)).
18.02.2003 01:48:50  ANE4952I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects inspected:   26,680
18.02.2003 01:48:50  ANE4954I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects backed up:2,255
18.02.2003 01:48:50  ANE4958I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects updated:  2
18.02.2003 01:48:50  ANE4960I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects rebound:  0
18.02.2003 01:48:50  ANE4957I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects deleted:  0
18.02.2003 01:48:50  ANE4970I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects expired:  1,207
18.02.2003 01:48:50  ANE4959I (Session: 1372430, Node: PAC2K340)  Total
number
  of objects failed:  11
18.02.2003 01:48:50  ANE4961I (Session: 1372430, Node: PAC2K340)  Total
number
  of bytes transferred: 1.72 GB
18.02.2003 01:48:50  ANE4963I (Session: 1372430, Node: PAC2K340)  Data
transfer
  time:2,994.31 sec
18.02.2003 01:48:50  ANE4966I (Session: 1372430, Node: PAC2K340)
Network data
  transfer rate:  603.65 KB/sec
18.02.2003 01:48:50  ANE4967I (Session: 1372430, Node: PAC2K340)
Aggregate
  data transfer rate:392.95 KB/sec
18.02.2003 01:48:50  ANE4968I (Session: 1372430, Node: PAC2K340)
Objects
  compressed by:6%
18.02.2003 01:48:50  ANE4964I (Session: 1372430, Node: PAC2K340)
Elapsed
  processing time:00:03:39
18.02.2003 01:48:53  ANR0403I Session 1369771 ended for node PAC2K340
(WinNT).
18.02.2003 02:25:35  ANR0406I Session 1374418 started for node PAC2K340
(WinNT)
  (Tcp/Ip xxx.xxx.xxx.xxx(1083)).
18.02.2003 02:26:09  ANR0406I Session 1374443 started for node PAC2K340
(WinNT)
  (Tcp/Ip xxx.xxx.xxx.xxx(1101)).

...skipped blah-blah

18.02.2003 02:29:53  ANE4952I (Session: 1374418, Node: PAC2K340)  Total
number
  of objects inspected:   26,666
18.02.2003 02:29:53  ANE4954I (Session: 1374418, Node: PAC2K340)  Total
number
  of objects backed up:2,078
18.02.2003 02:29:53  ANE4958I (Session: 1374418, Node: PAC2K340)  Total
number
  of objects updated:  3
18.02.2003 02:29:53  ANE4960I (Session: 1374418, Node: PAC2K340)  Total
number
  of objects rebound:  0
18.02.2003 02:29:53  ANE4957I (Session: 1374418, Node: PAC2K340)  Total
number
  of