• Please help support our sponsors by considering their products and services.
    Our sponsors enable us to serve you with this high-speed Internet connection and fast webservers you are currently using at ADSM.ORG.
    They support this free flow of information and knowledge exchange service at no cost to you.

    Please welcome our latest sponsor Tectrade . We can show our appreciation by learning more about Tectrade Solutions
  • Community Tip: Please Give Thanks to Those Sharing Their Knowledge.

    If you receive helpful answer on this forum, please show thanks to the poster by clicking "LIKE" link for the answer that you found helpful.

  • Community Tip: Forum Rules (PLEASE CLICK HERE TO READ BEFORE POSTING)

    Click the link above to access ADSM.ORG Acceptable Use Policy and forum rules which should be observed when using this website. Violators may be banned from this website. This notice will disappear after you have made at least 3 posts.

CAD service logging repeatedly during backups?

marclant

ADSM.ORG Moderator
#21
When you said you upgraded the server to 8.1, do you mean the Windows server that has the client, or the actual TSM Server? If the latter, upgrade the client as per:
Check dsmwebcl.log, just in case there are errors reported for CAD which would cause it to keep waking up the scheduler.

Also, it would be worth while to upgrade that client to 7.1.6 (or 8.1.0), just in case it's a defect. It would also bring you back into a support release.
And check the dsmwebcl.log as well to see what CAD is doing.
 

opeth

ADSM.ORG Member
#22
OK I think I may have figured it out, but I wont know for sure till the backups run tonight.
I set schedmode to ANY on server, noticed the client logs said it was not allowing a prompted backup. Which is odd because the old server I am migrating from had schedmode set any.
I changed server to schedulemode prompted and I saw the constant communications fall off the actlog and the cad services with the problem stop.

Strange.
 

opeth

ADSM.ORG Member
#24
well this is weird, setting it to prompted seemed to fix it, but as soon as the backup kicked off last night I get the issue again

The actlog looks like this from the moment it kicks off a backup (backup completes successfully) till about 8am


x86-64) (Tcp/Ip NODENAME.domain.com(40548)). (SESSION: 89804)
06/19/2017 23:25:07 ANR0403I Session 89804 ended for node NODENAME (Linux
x86-64). (SESSION: 89804)
06/19/2017 23:25:38 ANR0406I Session 89807 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40550)). (SESSION: 89807)
06/19/2017 23:25:38 ANR0403I Session 89807 ended for node NODENAME (Linux
x86-64). (SESSION: 89807)
06/19/2017 23:26:10 ANR0406I Session 89810 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40552)). (SESSION: 89810)
06/19/2017 23:26:10 ANR0403I Session 89810 ended for node NODENAME (Linux
x86-64). (SESSION: 89810)
06/19/2017 23:26:51 ANR0406I Session 89815 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40554)). (SESSION: 89815)
06/19/2017 23:26:51 ANR0403I Session 89815 ended for node NODENAME (Linux
x86-64). (SESSION: 89815)
06/19/2017 23:27:22 ANR0406I Session 89817 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40556)). (SESSION: 89817)
06/19/2017 23:27:22 ANR0403I Session 89817 ended for node NODENAME (Linux
x86-64). (SESSION: 89817)
06/19/2017 23:27:53 ANR0406I Session 89822 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40558)). (SESSION: 89822)
06/19/2017 23:27:53 ANR0403I Session 89822 ended for node NODENAME (Linux
x86-64). (SESSION: 89822)
06/19/2017 23:28:25 ANR0406I Session 89826 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40562)). (SESSION: 89826)
06/19/2017 23:28:25 ANR0403I Session 89826 ended for node NODENAME (Linux
x86-64). (SESSION: 89826)
06/19/2017 23:28:56 ANR0406I Session 89830 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40564)). (SESSION: 89830)
06/19/2017 23:28:56 ANR0403I Session 89830 ended for node NODENAME (Linux
x86-64). (SESSION: 89830)
06/19/2017 23:29:27 ANR0406I Session 89834 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40566)). (SESSION: 89834)
06/19/2017 23:29:27 ANR0403I Session 89834 ended for node NODENAME (Linux
x86-64). (SESSION: 89834)
06/19/2017 23:30:08 ANR0406I Session 89839 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40580)). (SESSION: 89839)
06/19/2017 23:30:08 ANR0403I Session 89839 ended for node NODENAME (Linux
x86-64). (SESSION: 89839)
06/19/2017 23:30:40 ANR0406I Session 89843 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40582)). (SESSION: 89843)
06/19/2017 23:30:40 ANR0403I Session 89843 ended for node NODENAME (Linux
x86-64). (SESSION: 89843)
06/19/2017 23:31:11 ANR0406I Session 89850 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40584)). (SESSION: 89850)
06/19/2017 23:31:11 ANR0403I Session 89850 ended for node NODENAME (Linux
x86-64). (SESSION: 89850)
06/19/2017 23:31:42 ANR0406I Session 89854 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40586)). (SESSION: 89854)
06/19/2017 23:31:42 ANR0403I Session 89854 ended for node NODENAME (Linux
x86-64). (SESSION: 89854)
06/19/2017 23:32:14 ANR0406I Session 89857 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40588)). (SESSION: 89857)
06/19/2017 23:32:14 ANR0403I Session 89857 ended for node NODENAME (Linux
x86-64). (SESSION: 89857)
06/19/2017 23:32:55 ANR0406I Session 89862 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40590)). (SESSION: 89862)
06/19/2017 23:32:55 ANR0403I Session 89862 ended for node NODENAME (Linux
x86-64). (SESSION: 89862)
06/19/2017 23:33:26 ANR0406I Session 89865 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40592)). (SESSION: 89865)
06/19/2017 23:33:26 ANR0403I Session 89865 ended for node NODENAME (Linux
x86-64). (SESSION: 89865)
06/19/2017 23:33:57 ANR0406I Session 89868 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40594)). (SESSION: 89868)
06/19/2017 23:33:57 ANR0403I Session 89868 ended for node NODENAME (Linux
x86-64). (SESSION: 89868)
06/19/2017 23:34:29 ANR0406I Session 89871 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40596)). (SESSION: 89871)
06/19/2017 23:34:29 ANR0403I Session 89871 ended for node NODENAME (Linux
x86-64). (SESSION: 89871)
06/19/2017 23:35:00 ANR0406I Session 89875 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40598)). (SESSION: 89875)
06/19/2017 23:35:00 ANR0403I Session 89875 ended for node NODENAME (Linux
x86-64). (SESSION: 89875)
06/19/2017 23:35:31 ANR0406I Session 89879 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40612)). (SESSION: 89879)
06/19/2017 23:35:31 ANR0403I Session 89879 ended for node NODENAME (Linux
x86-64). (SESSION: 89879)
06/19/2017 23:36:12 ANR0406I Session 89883 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40614)). (SESSION: 89883)
06/19/2017 23:36:12 ANR0403I Session 89883 ended for node NODENAME (Linux
x86-64). (SESSION: 89883)
06/19/2017 23:36:44 ANR0406I Session 89886 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40616)). (SESSION: 89886)
06/19/2017 23:36:44 ANR0403I Session 89886 ended for node NODENAME (Linux
x86-64). (SESSION: 89886)
06/19/2017 23:37:15 ANR0406I Session 89890 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40618)). (SESSION: 89890)
06/19/2017 23:37:15 ANR0403I Session 89890 ended for node NODENAME (Linux
x86-64). (SESSION: 89890)
06/19/2017 23:37:46 ANR0406I Session 89893 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40620)). (SESSION: 89893)
06/19/2017 23:37:46 ANR0403I Session 89893 ended for node NODENAME (Linux
x86-64). (SESSION: 89893)
06/19/2017 23:38:17 ANR0406I Session 89896 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40622)). (SESSION: 89896)
06/19/2017 23:38:17 ANR0403I Session 89896 ended for node NODENAME (Linux
x86-64). (SESSION: 89896)
06/19/2017 23:38:59 ANR0406I Session 89900 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40628)). (SESSION: 89900)
06/19/2017 23:38:59 ANR0403I Session 89900 ended for node NODENAME (Linux
x86-64). (SESSION: 89900)
06/19/2017 23:39:30 ANR0406I Session 89903 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40630)). (SESSION: 89903)
06/19/2017 23:39:30 ANR0403I Session 89903 ended for node NODENAME (Linux
x86-64). (SESSION: 89903)
06/19/2017 23:40:01 ANR0406I Session 89906 started for node NODENAME (Linux
x86-64) (Tcp/Ip NODENAME.domain.com(40644)). (SESSION: 89906)
06/19/2017 23:40:01 ANR0403I Session 89906 ended for node NODENAME (Linux .....


I can only assume this is something on the server, as the TSM server as that is the only part that has changed in this configuration.
I tried to update the client and it started backing up NFS shares for some reason, even tho the dsm.sys clearly says DOMAIN ALL-LOCAL so the customer wanted to revert back to the known good client.

Any thoughts ? Its like the client isn't getting the reply back it is requesting and just initiates another session but I have no idea what its looking for as it does have the schedule and the backup is working
 

opeth

ADSM.ORG Member
#25
dsm.sys file for one of the nodes doing this


SErvername SERVERNAME


TXNBYTELIMIT 50176K 

PASSWORDACCESS GENERATE 

TCPBUFFSIZE 64 

NODENAME NODENAME 

COMMmethod TCPip 

TCPPORT 1500 

TCPCLIENTADDRESS xxx.xx.xx.xxx

TCPCLIENTPORT 1501 

TCPServeraddress NEW SERVERNAME

PASSWORDAccess generate 

SCHEDMODE PRompted 

HTTPport 1581 

SCHEDLOGRetention N 

ERRORLOGRetention 60 D 

MANAGEDSERVICES schedule webclient 

WEBPORTS 2123 2124 

INCLEXCL "/opt/tivoli/tsm/client/ba/bin/dsm_exclude_files.excl"
 

opeth

ADSM.ORG Member
#28
Its full of this

06/19/2017 14:43:19 (dsmcad) Next operation scheduled:
06/19/2017 14:43:19 (dsmcad) ------------------------------------------------------------
06/19/2017 14:43:19 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 14:43:19 (dsmcad) Action: Incremental
06/19/2017 14:43:19 (dsmcad) Objects:
06/19/2017 14:43:19 (dsmcad) Options:
06/19/2017 14:43:19 (dsmcad) Server Window Start: 19:00:00 on 06/19/2017
06/19/2017 14:43:19 (dsmcad) ------------------------------------------------------------
06/19/2017 14:43:19 (dsmcad) Waiting to be contacted by the server.
06/19/2017 19:00:15 (dsmcad) Executing scheduled command now.
06/19/2017 19:03:27 (dsmcad) Next operation scheduled:
06/19/2017 19:03:27 (dsmcad) ------------------------------------------------------------
06/19/2017 19:03:27 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 19:03:27 (dsmcad) Action: Incremental
06/19/2017 19:03:27 (dsmcad) Objects:
06/19/2017 19:03:27 (dsmcad) Options:
06/19/2017 19:03:27 (dsmcad) Server Window Start: 19:00:00 on 06/20/2017
06/19/2017 19:03:27 (dsmcad) ------------------------------------------------------------
06/19/2017 19:03:27 (dsmcad) Waiting to be contacted by the server.
06/19/2017 22:10:17 (dsmcad) Executing scheduled command now.
06/19/2017 22:10:23 (dsmcad) Next operation scheduled:
06/19/2017 22:10:23 (dsmcad) ------------------------------------------------------------
06/19/2017 22:10:23 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 22:10:23 (dsmcad) Action: Incremental
06/19/2017 22:10:23 (dsmcad) Objects:
06/19/2017 22:10:23 (dsmcad) Options:
06/19/2017 22:10:23 (dsmcad) Server Window Start: 19:00:00 on 06/20/2017
06/19/2017 22:10:23 (dsmcad) ------------------------------------------------------------
06/19/2017 22:10:23 (dsmcad) Waiting to be contacted by the server.
06/19/2017 22:10:43 (dsmcad) Executing scheduled command now.
06/19/2017 22:10:45 (dsmcad) Next operation scheduled:
06/19/2017 22:10:45 (dsmcad) ------------------------------------------------------------
06/19/2017 22:10:45 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 22:10:45 (dsmcad) Action: Incremental
06/19/2017 22:10:45 (dsmcad) Objects:
06/19/2017 22:10:45 (dsmcad) Options:
06/19/2017 22:10:45 (dsmcad) Server Window Start: 19:00:00 on 06/20/2017
06/19/2017 22:10:45 (dsmcad) ------------------------------------------------------------
06/19/2017 22:10:45 (dsmcad) Waiting to be contacted by the server.
06/19/2017 22:11:15 (dsmcad) Executing scheduled command now.
06/19/2017 22:11:16 (dsmcad) Next operation scheduled:
06/19/2017 22:11:16 (dsmcad) ------------------------------------------------------------
06/19/2017 22:11:16 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 22:11:16 (dsmcad) Action: Incremental
06/19/2017 22:11:16 (dsmcad) Objects:
06/19/2017 22:11:16 (dsmcad) Options:
06/19/2017 22:11:16 (dsmcad) Server Window Start: 19:00:00 on 06/20/2017
06/19/2017 22:11:16 (dsmcad) ------------------------------------------------------------
06/19/2017 22:11:16 (dsmcad) Waiting to be contacted by the server.
06/19/2017 22:11:56 (dsmcad) Executing scheduled command now.
06/19/2017 22:11:57 (dsmcad) Next operation scheduled:
06/19/2017 22:11:57 (dsmcad) ------------------------------------------------------------
06/19/2017 22:11:57 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 22:11:57 (dsmcad) Action: Incremental
06/19/2017 22:11:57 (dsmcad) Objects:
06/19/2017 22:11:57 (dsmcad) Options:
06/19/2017 22:11:57 (dsmcad) Server Window Start: 19:00:00 on 06/20/2017
06/19/2017 22:11:57 (dsmcad) ------------------------------------------------------------
06/19/2017 22:11:57 (dsmcad) Waiting to be contacted by the server.
06/19/2017 22:12:27 (dsmcad) Executing scheduled command now.
06/19/2017 22:12:28 (dsmcad) Next operation scheduled:
06/19/2017 22:12:28 (dsmcad) ------------------------------------------------------------
06/19/2017 22:12:28 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 22:12:28 (dsmcad) Action: Incremental
06/19/2017 22:12:28 (dsmcad) Objects:
06/19/2017 22:12:28 (dsmcad) Options:
06/19/2017 22:12:28 (dsmcad) Server Window Start: 19:00:00 on 06/20/2017
06/19/2017 22:12:28 (dsmcad) ------------------------------------------------------------
06/19/2017 22:12:28 (dsmcad) Waiting to be contacted by the server.
06/19/2017 22:12:58 (dsmcad) Executing scheduled command now.
06/19/2017 22:13:00 (dsmcad) Next operation scheduled:
06/19/2017 22:13:00 (dsmcad) ------------------------------------------------------------
06/19/2017 22:13:00 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 22:13:00 (dsmcad) Action: Incremental
06/19/2017 22:13:00 (dsmcad) Objects:
06/19/2017 22:13:00 (dsmcad) Options:
06/19/2017 22:13:00 (dsmcad) Server Window Start: 19:00:00 on 06/20/2017
06/19/2017 22:13:00 (dsmcad) ------------------------------------------------------------
06/19/2017 22:13:00 (dsmcad) Waiting to be contacted by the server.
06/19/2017 22:13:30 (dsmcad) Executing scheduled command now.
06/19/2017 22:13:31 (dsmcad) Next operation scheduled:
06/19/2017 22:13:31 (dsmcad) ------------------------------------------------------------
06/19/2017 22:13:31 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 22:13:31 (dsmcad) Action: Incremental
06/19/2017 22:13:31 (dsmcad) Objects:
06/19/2017 22:13:31 (dsmcad) Options:
06/19/2017 22:13:31 (dsmcad) Server Window Start: 19:00:00 on 06/20/2017
06/19/2017 22:13:31 (dsmcad) ------------------------------------------------------------
06/19/2017 22:13:31 (dsmcad) Waiting to be contacted by the server.
06/19/2017 22:14:01 (dsmcad) Executing scheduled command now.
06/19/2017 22:14:02 (dsmcad) Next operation scheduled:
06/19/2017 22:14:02 (dsmcad) ------------------------------------------------------------
06/19/2017 22:14:02 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 22:14:02 (dsmcad) Action: Incremental
06/19/2017 22:14:02 (dsmcad) Objects:
06/19/2017 22:14:02 (dsmcad) Options:
06/19/2017 22:14:02 (dsmcad) Server Window Start: 19:00:00 on 06/20/2017
06/19/2017 22:14:02 (dsmcad) ------------------------------------------------------------
06/19/2017 22:14:02 (dsmcad) Waiting to be contacted by the server.
06/19/2017 22:14:32 (dsmcad) Executing scheduled command now.
06/19/2017 22:14:33 (dsmcad) Next operation scheduled:
06/19/2017 22:14:33 (dsmcad) ------------------------------------------------------------
06/19/2017 22:14:33 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 22:14:33 (dsmcad) Action: Incremental
06/19/2017 22:14:33 (dsmcad) Objects:
06/19/2017 22:14:33 (dsmcad) Options:
06/19/2017 22:14:33 (dsmcad) Server Window Start: 19:00:00 on 06/20/2017
06/19/2017 22:14:33 (dsmcad) ------------------------------------------------------------
06/19/2017 22:14:33 (dsmcad) Waiting to be contacted by the server.
06/19/2017 22:15:13 (dsmcad) Executing scheduled command now.
06/19/2017 22:15:15 (dsmcad) Next operation scheduled:
06/19/2017 22:15:15 (dsmcad) ------------------------------------------------------------
06/19/2017 22:15:15 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 22:15:15 (dsmcad) Action: Incremental
06/19/2017 22:15:15 (dsmcad) Objects:
06/19/2017 22:15:15 (dsmcad) Options:
06/19/2017 22:15:15 (dsmcad) Server Window Start: 19:00:00 on 06/20/2017
06/19/2017 22:15:15 (dsmcad) ------------------------------------------------------------
06/19/2017 22:15:15 (dsmcad) Waiting to be contacted by the server.
06/19/2017 22:15:45 (dsmcad) Executing scheduled command now.
06/19/2017 22:15:46 (dsmcad) Next operation scheduled:
06/19/2017 22:15:46 (dsmcad) ------------------------------------------------------------
06/19/2017 22:15:46 (dsmcad) Schedule Name: SCHEDULE1
06/19/2017 22:15:46 (dsmcad) Action: Incremental
06/19/2017 22:15:46 (dsmcad) Objects:
06/19/2017 22:15:46 (dsmcad) Options:
06/19/2017 22:15:46 (dsmcad) Server Window Start: 19:00:00 on 06/20/2017
 

marclant

ADSM.ORG Moderator
#29
It's really odd. I'd upgrade the client to a supported level and open a problem ticket with IBM if I were you. Supported are 6.4.0 or later, but 7.1.0 and later after September.
 

opeth

ADSM.ORG Member
#31
Ok this is ever more weird. If I set the schedule for noon, I restart the cad and it finds the new schedule, does NOT loop like the problem I posted, runs its backup and completes and acts completely normal. I don't think this has anything to do with the cad or the scheduler at all. Its also not happening to all nodes, only a specific few.

Is there ANYTHING server that is a time based setting that could allow/force a client to poll ?

Marclay that's for the help, but I cant upgrade until IBM gets the client NFS automount issue fixed (projected 8.1.2) Kind of stuck in a hard place here. If I log a ticket I know they are going to tell me to upgrade the client first thing. I guess I will just have to log it and go through the explanation.
 

opeth

ADSM.ORG Member
#33
SERVER_1 = DOMAIN_A SCHED_A (Linux)
Backup finished 19:02
Logging issue: 22:10:19 - 8:15 (10 hours)

SERVER_2 = DOMAIN_A SCHED_B (Linux)
Backup finished 20:05
Logging issue: 22:10 - 8:09 (10 hours)

SERVER_3 = DOMAIN_A SCHED_B (Linux)
Backup finsihed 20:03
Logging issue 20:04 - 5:59 (10 hours)

SERVER_4 =DOMAIN_C SCHED_C (Solaris)
Backup finished 00:38
Logging issue 00:38 - 8:09 (8 hours)
 

opeth

ADSM.ORG Member
#34
IBM isnt getting anywhere with this.

I pointed the backups to the original TSM server, and having the SAME problem, but noticed the logging occurs according to the schedules defined on the new server??!! Its like the CAD is holding on to the schedules and not "flushing" them out.
 

Advertise at ADSM.ORG

If you are reading this, so are your potential customer. Advertise at ADSM.ORG right now.

UpCloud high performance VPS at $5/month

Get started with $25 in credits on Cloud Servers. You must use link below to receive the credit. Use the promo to get upto 5 month of FREE Linux VPS.

The Spectrum Protect TLA (Three-Letter Acronym): ISP or something else?

  • Every product needs a TLA, Let's call it ISP (IBM Spectrum Protect).

    Votes: 7 23.3%
  • Keep using TSM for Spectrum Protect.

    Votes: 16 53.3%
  • Let's be formal and just say Spectrum Protect

    Votes: 4 13.3%
  • Other (please comement)

    Votes: 3 10.0%

Forum statistics

Threads
30,888
Messages
131,415
Members
21,194
Latest member
jamesmacd40