Page 1 of 1

952 Excessive Cube Dependency entries on log

Posted: Thu Mar 01, 2012 5:34 pm
by David Usherwood
Not sure why they are suddenly happening but I thought it was worth posting in case someone else had seen this.
48106 019 866.
We are testing using Parallel Interaction on a complex calculation
intensive application. After some promising tests (after applying HF6,
which includes the relevant optimisation) we are finding that the
server,on startup, is writing excessive cube dependency entries to
TM1SERVER.LOG, which is filling up and generating multiple .1/2/3
versions. The server eventually runs out of RAM.

Re: 952 Excessive Cube Dependency entries on log

Posted: Fri Mar 02, 2012 7:55 am
by lotsaram
We have a very similar issue also in a calculation intensive model using PI. We find that the cube dependency entries are written repeatedly to the message log even though they have already been set. We had the same issue in 9.5.1 before upgrading to 9.5.2 so I'm not sure if PI is a relevant factor. It isn't so bad in our case that the message log fills up to the extent that it goes over the 80MB limit that and starts new successive logs but it is irksome all the same as presumably this has locking implications. Once set a cube dependency should be retained for the duration of the server session, that's it period.

Re: 952 Excessive Cube Dependency entries on log

Posted: Fri Mar 02, 2012 12:01 pm
by David Usherwood
Interesting to hear it's happening elsewhere. Oddly, this wasn't happening when I started the testing, but I've tried turning PI off without any effect. I look forward (yeah right ;) ) to IBM's response.

Re: 952 Excessive Cube Dependency entries on log

Posted: Fri Mar 02, 2012 1:59 pm
by George Regateiro
Just a shot in the dark, is there anyway you could narrow it down to possibly a specific cube and then rules within the cube? We had an issue when upgrading to 9.5.2 (from 9.4) where we started seeing excessive logging of errors on a model that had not changed. Turned out to get around a possible crash based on a valid rule syntax IBM just started logging a cryptic error repeatedly. Your issue seems like TM1 is doing something similar when it tries to evaluate the the rules and is continually generating this. I know they modified the rule logging slightly between the versions.

Like I said a shot in the dark.

Re: 952 Excessive Cube Dependency entries on log

Posted: Mon Mar 05, 2012 11:28 am
by David Usherwood
Thanks for the thought. I'm pretty sure that we've changed nothing from the tests we run just before the flood of messages started, and the messages refer to the majority of the (large number of) active cubes in the (very large) system. IBM advised me to change the entries in tm1s-log.properties, which doesn't exist :) (The docs say it should sit with tm1s.cfg, so I think I've looked in the right place.)
Hey ho - just when I was getting some good results from using PI with a calculation intensive app.

Re: 952 Excessive Cube Dependency entries on log

Posted: Mon Mar 05, 2012 12:20 pm
by lotsaram
David Usherwood wrote:...IBM advised me to change the entries in tm1s-log.properties, which doesn't exist :) (The docs say it should sit with tm1s.cfg, so I think I've looked in the right place.)
Just save the following as "tm1s-log.properties" as a plain text file in the config directory.

Code: Select all

##  Enable INFO level logging through the shared memory appender, by default.  The server 
##  will write informational messages, as well as errors and warnings to the log file.

log4j.logger.TM1=INFO, S1

# S1 is set to be a SharedMemoryAppender
log4j.appender.S1=org.apache.log4j.SharedMemoryAppender

# Specify the size of the shared memory segment
log4j.appender.S1.MemorySize=5 MB

# Specify the max filesize
log4j.appender.S1.MaxFileSize=100 MB

# Specify the max backup index
log4j.appender.S1.MaxBackupIndex=20

# Specify GMT or Local timezone
log4j.appender.S1.TimeZone=GMT

Re: 952 Excessive Cube Dependency entries on log

Posted: Mon Mar 05, 2012 3:43 pm
by David Usherwood
Thanks.
In the meantime I'd done more or less that and the flood of irrelevant messages had stopped. Not good that the server 'default' behaviour had flipped around without any other changes made :evil:

Re: 952 Excessive Cube Dependency entries on log

Posted: Wed Mar 07, 2012 11:06 am
by Andy Key
Just hit the same thing, the line that I added to the tm1s-log.properties file was

Code: Select all

Log4j.logger.TM1.Cube.Dependency=WARN
rather than what all the links that I could find on the IBM web maze were saying (=INFO).

To be fair, they were saying use =INFO to identify your cube dependencies, but that seemed to be the default anyway, as my vanilla FP1 was showing a couple of hundred INFO level cube dependency messages with no specific entry in the properties file rather than the multi gigabyte log files that HF6 was creating.

Impressed by the speed at which it created them though...

Re: 952 Excessive Cube Dependency entries on log

Posted: Wed Mar 07, 2012 10:02 pm
by lotsaram
Interestingly there was a documentation technote email on this just today ...
http://www.ibm.com/support/docview.wss? ... RXT&mync=E

However this section is really not very clear.
IBM Cognos TM1 9.4.1 FP3 introduced a change to the dependency mapping to make Cognos TM1 more stable and to perform better.
There is an artifact of this change that users upgrading to Cognos TM1 9.4.1 FP3 and above should understand. In previous releases, this dependency map between cubes was established when rules were executed that referenced other cubes. However, these dependencies were cleared when there was any invalidation between the cubes and these dependencies would again be re-established once the rule was run to establish the dependency.
Dependency behavior now follows these rules:
Dependencies once established are NOT cleared based on data invalidation.
Cube dependencies can be established ahead of time using the AddCubeDependency TM1 ICAS function.
The article goes on to clarify that in 10.1 the behavior is that dependency relationships once established are only broken by 1/ server shutdown, 2/ rule save and 3/ dimension save (as this forces a rule recompile). But what isn't clear is for versions 9.4.1.3 to 9.5.2.1 inclusive is this also the case or is the dependency also invalidated on data change as per the quote above? (in which case the dependency isn't worth much in a planning model and might explain the repeated entries)

Re: 952 Excessive Cube Dependency entries on log

Posted: Wed Mar 14, 2012 1:42 am
by Andy Key
That document (http://www-01.ibm.com/support/docview.w ... RXT&mync=E) has now been updated and leads to a few conclusions:

1) 952 FP2 will either be released ahead of the April schedule (http://www-01.ibm.com/software/data/cog ... packs.html) or they are being a bit quick off the mark with documentation updates
IBM wrote:In the 9.5.2 FP2 and 10.1 version of the product this parameter is by default set to "true". In that case, rule based inter-cube DB(…) dependencies are detected and set automatically at server startup time.
2) As FP2 is now specifically mentioned, it would suggest that the default setting for FP1 was "false", although the appearance of CubeDependency INFO messages during FP1 (pre HF6) startup would conflict with that.

3) They've fixed the issue that was the original topic of this thread
IBM wrote:For example, when the following command is added to the the tm1s-log.properties file:

log4j.logger.TM1.Cube.Dependency=DEBUG
(This used to say =INFO) Although their example...
IBM wrote:The following information is returned that identifies dependencies:

INFO 2010-06-09 18:09:23.728 TM1.Cube.Dependency Adding cube dependency: cube "}ElementSecurity_}Cubes" depends on cube "}CubeSecurity"
...still shows this as an INFO message.

Re: 952 Excessive Cube Dependency entries on log

Posted: Tue Mar 27, 2012 1:09 pm
by David Usherwood
I've reopened the PMR. If I set
Log4j.logger.TM1.Cube.Dependency=WARN
The startup still generates millions of irrelevant, repetitive INFO messages. I can turn _all_ logging off and then change back after startup, but why? :x