TM1 server registering with Admin server

Post Reply
Wim Gielis
MVP
Posts: 2425
Joined: Mon Dec 29, 2008 6:26 pm
OLAP Product: TM1
Version: PAL 2.0.8
Excel Version: Office 365 - latest
Location: Brussels, Belgium
Contact:

TM1 server registering with Admin server

Post by Wim Gielis » Sun May 03, 2020 12:55 pm

Hello all,

In one of our TM1 environments, we suddenly see an issue with weekly restarts on Sunday.

In fact, there are 2 models on 1 server, who should register themselves with 1 admin host.
On Sunday morning, there is an automatic restart of the big model - Task Scheduler executes a batch script that reads:

Code: Select all

@ECHO OFF
SET SERVICE=THE_SERVICE_NAME

( SC STOP %SERVICE% && SC start %SERVICE% ) || ( TIMEOUT /T 3600 /NOBREAK && SC start %SERVICE% )
The small model is not restarted at all.

Now, this setup runs fine for now about 5 years. 3 weeks ago the TM1 server unregistered with the TM1 admin server but did not register again.
So the TM1 models loads fine but does not send out a signal to the TM1 admin server. Therefore, users don't see the server. When manually stopping the service and starting again, the TM1 server can register fine and it's all good.

Does anyone have an idea what is going on ? I increased the logging from INFO to DEBUG, but I don't see any clear culprit. Searching for ERROR or a cursory look do not help, the word ERROR is not in the logs and I see nothing out of the ordinary anyway. The logs from 8.30 AM to 2 PM is about 45,000 lines so without any pointer that will be difficult.

Thanks for any pointers !

Wim
Best regards,

Wim Gielis

Excel Most Valuable Professional, 2011-2014
https://www.wimgielis.com ==> 112 TM1 articles and a lot of custom code
Newest blog article: Selecting elements in the Subset Editor quickly

Wim Gielis
MVP
Posts: 2425
Joined: Mon Dec 29, 2008 6:26 pm
OLAP Product: TM1
Version: PAL 2.0.8
Excel Version: Office 365 - latest
Location: Brussels, Belgium
Contact:

Re: TM1 server registering with Admin server

Post by Wim Gielis » Sun May 03, 2020 1:02 pm

Here's a small part from the logs, just before the UNREGISTER takes place:

Code: Select all

10504   DEBUG   2020-05-03 08:30:00,427   TM1.TM1AdmSvr   RECEIVED PING: "MY_TM1_SERVICE","tcp","10.32.1.153","12347","1460","0","127.0.0.1","","1","1","tm1server","applixca.pem","","0","","0","","ipv4","42","0","1","https://HOST_MACHINE:8001","8001"
10504   DEBUG   2020-05-03 08:30:00,427   TM1.Server.Network   internal_net_Recv select on: 772
10504   DEBUG   2020-05-03 08:30:00,427   TM1.Server.Network   internal_net_Recv select returned: 1
10504   DEBUG   2020-05-03 08:30:00,427   TM1.Server.Memory   al_FreePool  -  apifunc# "0" - pool# "0" - poolsize "37158.000000"
2188   DEBUG   2020-05-03 08:30:01,551   TM1.Server.Memory   al_OpenPool() - apifunc# "0" - pool# "185" - Address "0x0000000000590300"
2188   DEBUG   2020-05-03 08:30:01,551   TM1.Event   mt_SetEvent: Set event 0x000000000000025C succeeded.
2192   DEBUG   2020-05-03 08:30:01,551   TM1.Event   mt_WaitForMultipleObjects: Successful. Event 0 (0x000000000000025C) signalled.
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Comm.SSL   SSL Connection accepted.
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Comm.SSL   Available ciphers:
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: DHE-RSA-AES256-SHA
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: DHE-DSS-AES256-SHA
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: AES256-SHA
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: EDH-RSA-DES-CBC3-SHA
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: EDH-DSS-DES-CBC3-SHA
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: DES-CBC3-SHA
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: DHE-RSA-AES128-SHA
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: DHE-DSS-AES128-SHA
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: AES128-SHA
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Comm.SSL   Cipher used for connection: Version: TLSv1/SSLv3, Name: DHE-RSA-AES256-SHA
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Server.Network   internal_net_Recv select on: 752
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Server.Network   internal_net_Recv select returned: 1
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Server.Network.Detail   Receive 15  bytes
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Server.Network.Detail   Send 8  bytes
7664   INFO   2020-05-03 08:30:01,551   TM1.TM1AdmSvr   REQUEST TO UNREGISTER: success - MY_TM1_SERVICE
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Server.Network   internal_net_Recv select on: 752
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Server.Network   internal_net_Recv select returned: 1
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Server.Network.Detail   Receive 8  bytes
7664   DEBUG   2020-05-03 08:30:01,551   TM1.Server.Memory   al_FreePool  -  apifunc# "0" - pool# "0" - poolsize "37158.000000"
2188   DEBUG   2020-05-03 08:30:02,892   TM1.Server.Memory   al_OpenPool() - apifunc# "0" - pool# "185" - Address "0x0000000000590300"
2188   DEBUG   2020-05-03 08:30:02,892   TM1.Event   mt_SetEvent: Set event 0x000000000000025C succeeded.
2192   DEBUG   2020-05-03 08:30:02,892   TM1.Event   mt_WaitForMultipleObjects: Successful. Event 0 (0x000000000000025C) signalled.
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Comm.SSL   SSL Connection accepted.
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Comm.SSL   Available ciphers:
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: DHE-RSA-AES256-SHA
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: DHE-DSS-AES256-SHA
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: AES256-SHA
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: EDH-RSA-DES-CBC3-SHA
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: EDH-DSS-DES-CBC3-SHA
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: DES-CBC3-SHA
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: DHE-RSA-AES128-SHA
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: DHE-DSS-AES128-SHA
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Comm.SSL   Cipher Version: TLSv1/SSLv3, Name: AES128-SHA
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Comm.SSL   Cipher used for connection: Version: TLSv1/SSLv3, Name: DHE-RSA-AES256-SHA
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Server.Network   internal_net_Recv select on: 764
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Server.Network   internal_net_Recv select returned: 1
8796   DEBUG   2020-05-03 08:30:02,892   TM1.Server.Network.Detail   Receive 176  bytes
Best regards,

Wim Gielis

Excel Most Valuable Professional, 2011-2014
https://www.wimgielis.com ==> 112 TM1 articles and a lot of custom code
Newest blog article: Selecting elements in the Subset Editor quickly

Wim Gielis
MVP
Posts: 2425
Joined: Mon Dec 29, 2008 6:26 pm
OLAP Product: TM1
Version: PAL 2.0.8
Excel Version: Office 365 - latest
Location: Brussels, Belgium
Contact:

Re: TM1 server registering with Admin server

Post by Wim Gielis » Sun May 03, 2020 3:51 pm

I did some more digging:
- I changed the timeout for restart from 3,600 seconds to 600 seconds (just for testing purposes).
- I created a new task in Task Scheduler to execute this task about half an hour ago, which is Sunday evening for me.

Guess what, TM1 stops and starts and registers itself with the TM1 admin server if I use this script and task.

The differences are:
- 600 sec of timeout instead of 3600
- Sunday evening instead of Sunday morning
- the model was not used since the last restart this afternoon. The Sunday morning restart was after a week of TM1 usage
- my user to create the task, I am admin on the machine though, and the current task was set up by an admin person at the customer (who will definitely not be less admin than me)

Does anyone have a clue ?
Best regards,

Wim Gielis

Excel Most Valuable Professional, 2011-2014
https://www.wimgielis.com ==> 112 TM1 articles and a lot of custom code
Newest blog article: Selecting elements in the Subset Editor quickly

User avatar
ykud
Posts: 88
Joined: Sat Jan 10, 2009 10:52 am
Contact:

Re: TM1 server registering with Admin server

Post by ykud » Mon May 04, 2020 3:46 am

Anything interesting in Admin server log?
https://www.ibm.com/support/knowledgece ... 600ba.html
I'd put in debug for next weekend to see whether there was a comm error.

Anything interesting in the Windows Event log around the time? You should see Service Stop / Service start entries there, but maybe there's something else?

What version you're on? If it's 2.0.9, might be worth looking into what admin server 'sees' via rest api and 'adding' it again -- this might give you a better error log?
https://www.ibm.com/support/knowledgece ... pport.html


And the usual : was antivirus changed / updated in the last month and is now clever enough to 'kill some of these messages'? :)

Wim Gielis
MVP
Posts: 2425
Joined: Mon Dec 29, 2008 6:26 pm
OLAP Product: TM1
Version: PAL 2.0.8
Excel Version: Office 365 - latest
Location: Brussels, Belgium
Contact:

Re: TM1 server registering with Admin server

Post by Wim Gielis » Mon May 04, 2020 8:22 am

Hi ykud,

Thanks !

In the admin server logging, there's a lot of entries if DEBUG is enabled, like I did. In this thread I wrote that I didn't see anything out of the ordinary. Unfortunately, I cannot compare with DEBUG outcomes of the period when it used to work, 3 weeks ago. DEBUG was already active last weekend and the files exist.

Windows Event log was checked too, it gives 2 messages related to the said service:
- 8.30 service stopped
- 9.30 service started

Only thing is, the service did not signal this fact to the admin server, it seems.

The version is really outdated and unsupported, it's TM1 10.2.2 FP4. So no help with IBM. But since this setup has been around forever I don't think it is different from what we now have as a setup.

I will ask IT about antivirus or anything else that changed since let's say last month.

Wim
Best regards,

Wim Gielis

Excel Most Valuable Professional, 2011-2014
https://www.wimgielis.com ==> 112 TM1 articles and a lot of custom code
Newest blog article: Selecting elements in the Subset Editor quickly

Drg
Posts: 147
Joined: Fri Aug 12, 2016 10:02 am
OLAP Product: tm1
Version: 10.2.0 - 10.3.0
Excel Version: 2010

Re: TM1 server registering with Admin server

Post by Drg » Mon May 04, 2020 9:51 am

So the model doesn’t appear on the admin host at all, or does it appear during a manual start?
For reliability, try on both servers (the host and model server) to start the tm1 configurator and re-save the model with the creation of cryptography. and restart the admin host with saving the config file.

We had such an error when traffic analyzers stood between the subnets and blocked it (which of course does not fit into the situation if the model is visible during a manual start).
In any case, the best option would be to check the traffic on both servers during different launches.
Good luck

Wim Gielis
MVP
Posts: 2425
Joined: Mon Dec 29, 2008 6:26 pm
OLAP Product: TM1
Version: PAL 2.0.8
Excel Version: Office 365 - latest
Location: Brussels, Belgium
Contact:

Re: TM1 server registering with Admin server

Post by Wim Gielis » Mon May 04, 2020 10:10 am

Thank you Drg.

It’s all on 1 machine.
1 admin host and 2 TM1 models. A very small one (0.5 GB) and a bigger one (60 GB).

During manual restart, or even my test scheduled restart on Sunday evening, the TM1 server can notify the admin server.

But this went wrong on Sunday morning for the past 3 weeks. The 5 years before it worked without an issue.
Best regards,

Wim Gielis

Excel Most Valuable Professional, 2011-2014
https://www.wimgielis.com ==> 112 TM1 articles and a lot of custom code
Newest blog article: Selecting elements in the Subset Editor quickly

tomok
MVP
Posts: 2724
Joined: Tue Feb 16, 2010 2:39 pm
OLAP Product: TM1, Palo
Version: Beginning of time thru 10.2
Excel Version: 2003-2007-2010-2013
Location: Atlanta, GA
Contact:

Re: TM1 server registering with Admin server

Post by tomok » Mon May 04, 2020 11:40 am

A stupid question but you do have a SaveData chore executing before your batch file takes down the TM1 service, right? If you don't it will save the data during the takedown, which can take a while if the service has been up for a long time. Maybe this is why it works fine with the extra timeout.
Tom O'Kelley - Manager Finance Systems
American Tower
http://www.onlinecourtreservations.com/

Drg
Posts: 147
Joined: Fri Aug 12, 2016 10:02 am
OLAP Product: tm1
Version: 10.2.0 - 10.3.0
Excel Version: 2010

Re: TM1 server registering with Admin server

Post by Drg » Mon May 04, 2020 5:13 pm

tomok wrote:
Mon May 04, 2020 11:40 am
A stupid question but you do have a SaveData chore executing before your batch file takes down the TM1 service, right? If you don't it will save the data during the takedown, which can take a while if the service has been up for a long time. Maybe this is why it works fine with the extra timeout.
In practice, quite a few people were faced with situations when the server simply could not repay without forcing the process to stop (taskkill / f), this happens if executecommand was started which did not end or if a big view was opened and the server issued a message about its suspension.

but as I understand the problem is broader than those windows event shows that the service is stopped? or in the process of stopping?

Wim Gielis
MVP
Posts: 2425
Joined: Mon Dec 29, 2008 6:26 pm
OLAP Product: TM1
Version: PAL 2.0.8
Excel Version: Office 365 - latest
Location: Brussels, Belgium
Contact:

Re: TM1 server registering with Admin server

Post by Wim Gielis » Wed May 06, 2020 8:44 pm

tomok wrote:
Mon May 04, 2020 11:40 am
A stupid question but you do have a SaveData chore executing before your batch file takes down the TM1 service, right? If you don't it will save the data during the takedown, which can take a while if the service has been up for a long time. Maybe this is why it works fine with the extra timeout.
Hi Tom,

There's a savedata at 7.30 AM and it takes about 30 min usually. It's a daily chore. I will look in the server message log to see when then the save data stopped that morning. It could be that it clashes with the restart. Maybe because we went to summertime end of March... The restart is at 8.30 AM but this sounds like a possibility to check out !
Best regards,

Wim Gielis

Excel Most Valuable Professional, 2011-2014
https://www.wimgielis.com ==> 112 TM1 articles and a lot of custom code
Newest blog article: Selecting elements in the Subset Editor quickly

Wim Gielis
MVP
Posts: 2425
Joined: Mon Dec 29, 2008 6:26 pm
OLAP Product: TM1
Version: PAL 2.0.8
Excel Version: Office 365 - latest
Location: Brussels, Belgium
Contact:

Re: TM1 server registering with Admin server

Post by Wim Gielis » Wed May 06, 2020 8:50 pm

No, the Savedata was successful and surely before the restart. This was the situation last Sunday morning:
02.png
02.png (43.26 KiB) Viewed 645 times
That will not be the problem either.
Best regards,

Wim Gielis

Excel Most Valuable Professional, 2011-2014
https://www.wimgielis.com ==> 112 TM1 articles and a lot of custom code
Newest blog article: Selecting elements in the Subset Editor quickly

Wim Gielis
MVP
Posts: 2425
Joined: Mon Dec 29, 2008 6:26 pm
OLAP Product: TM1
Version: PAL 2.0.8
Excel Version: Office 365 - latest
Location: Brussels, Belgium
Contact:

Re: TM1 server registering with Admin server

Post by Wim Gielis » Sun May 10, 2020 10:19 am

Today I rescheduled the restart to take place 3 hours later (through the same batch script), still on Sunday before noon. Now it runs fine. Will check back next week too. No idea why it ran fine in the morning for 5 years and now all of a sudden it gave a timing issue (or so it seems).
Best regards,

Wim Gielis

Excel Most Valuable Professional, 2011-2014
https://www.wimgielis.com ==> 112 TM1 articles and a lot of custom code
Newest blog article: Selecting elements in the Subset Editor quickly

User avatar
gtonkin
MVP
Posts: 785
Joined: Thu May 06, 2010 3:03 pm
OLAP Product: TM1
Version: PAL 2.0.3
Excel Version: 2016 64-bit
Location: JHB, South Africa
Contact:

Re: TM1 server registering with Admin server

Post by gtonkin » Sun May 10, 2020 11:24 am

Anything is the event viewer during the old time window?
Any new scheduled tasks running, updates being applied, AV scans?

Wim Gielis
MVP
Posts: 2425
Joined: Mon Dec 29, 2008 6:26 pm
OLAP Product: TM1
Version: PAL 2.0.8
Excel Version: Office 365 - latest
Location: Brussels, Belgium
Contact:

Re: TM1 server registering with Admin server

Post by Wim Gielis » Sun May 17, 2020 11:36 am

gtonkin wrote:
Sun May 10, 2020 11:24 am
Anything is the event viewer during the old time window?
Any new scheduled tasks running, updates being applied, AV scans?
Thanks all !

Confirmation: the automatic restart is again successful this Sunday. I only scheduled the restart 3 hours later compared to before.
A direct cause as to why the previous timing (8.30 AM) suddenly gives issues after 5 years, was not found, unfortunately.
Best regards,

Wim Gielis

Excel Most Valuable Professional, 2011-2014
https://www.wimgielis.com ==> 112 TM1 articles and a lot of custom code
Newest blog article: Selecting elements in the Subset Editor quickly

Post Reply