How to diagnose MLServer performance issue?

Post here issues and solutions that relate to MainLobby Server 3
User avatar
simonmason
Expert
Expert
Posts: 855
Joined: Tue Dec 26, 2006 9:06 pm
Contact:

How to diagnose MLServer performance issue?

Postby simonmason » Sat Nov 27, 2010 8:11 am

How can you figure out what is going on with MLServer when it is under heavy load? Several times over the last week or so the server has been extremely slow - touches take almost a minute or more to respond. It doesn't seem to clear itself - I usually end up restarting the server. I am running 3.75.213. I would like to figure out what is causing the slowdown but I don't know where to start - the logs? What would I look for?
Simon D. S. Mason

User avatar
CinemarDave
Site Admin
Site Admin
Posts: 10535
Joined: Fri Feb 07, 2003 8:56 am
Location: Planet Earth
Contact:

Re: How to diagnose MLServer performance issue?

Postby CinemarDave » Sat Nov 27, 2010 12:04 pm

The MLServer verbose event logs are the first place to start. They will show the timing between commands and the number of commands queued up. This will not pinpoint the issue. The most likely cause is always a plugin that is doing something in a loop or waiting for a web request that ties up the system. From tracking the activity in the MLServer event log you should get an idea as to what plugins were doing work. Once you do that you can then start to look at the individual plugin event logs to what what their timings are and what they are doing.

User avatar
simonmason
Expert
Expert
Posts: 855
Joined: Tue Dec 26, 2006 9:06 pm
Contact:

Re: How to diagnose MLServer performance issue?

Postby simonmason » Sun Jan 16, 2011 8:36 am

I continue to have this problem periodically. It is happening to me right now so I turned on verbose logging. I am looking through the logs and I do see plenty of things going on but nothing looks suspicious to my untrained eye. I have included a copy of it below if this helps to diagnose the issues? I am about to restart the server because that invariably clears it up and things go back to normal.


Code: Select all

1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF_ReportTimeAmPm=AM
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF_ReportTimeDOW=Sunday
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuleft_3=32
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuright_3=26
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuleft_3=38
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuright_3=34
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_DOW=Tuesday
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_DateUTC=1/18/2011 11 am
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_Date=1/18/2011 6 am
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_Time=6 am
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_DateYear=2011
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_DateMonth=1
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_DateDay=18
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_DateHour=6
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_DateMinute=00
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_DateSecond=00
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_DateAmPm=AM
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_DateDOW=Tuesday
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_NewDate=
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuleft_3=39
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuright_3=44
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuleft_3=31
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuright_3=32
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuleft_3=23
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuright_3=24
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_TempF=25
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_TempC=-3
1/16/2011 8:28:56 AM   System   SetVariableFast   MLWeather_HF46_SkyCode=14
1/16/2011 8:28:56 AM   System   SetVariable   192.168.1.160_timer02_time=53
1/16/2011 8:28:56 AM   System   SetVariable   192.168.1.160_timer02_timeHMS=00:53
1/16/2011 8:28:56 AM   System   SetVariable   192.168.1.160_timer_MLRSS_Next_Feed_time=53
1/16/2011 8:28:56 AM   System   SetVariable   192.168.1.160_timer_MLRSS_Next_Feed_timeHMS=00:53
1/16/2011 8:28:56 AM   System   SetVariable   MLTimer_timer02_time=53
1/16/2011 8:28:56 AM   System   SetVariable   MLTimer_timer02_timeHMS=00:53
1/16/2011 8:28:56 AM   System   SetVariable   MLTimer_timer_MLRSS_Next_Feed_time=53
1/16/2011 8:28:56 AM   System   SetVariable   MLTimer_timer_MLRSS_Next_Feed_timeHMS=00:53
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuleft_3=22
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuright_3=41
1/16/2011 8:28:56 AM   System   SetVariableClient   music_vuleft_3=29
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=36
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_SkyCodeExt=1400
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_Icon=74
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_SkyL=Snow Showers
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_SkyM=Snow Showers
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_SkyS=Snow Showers
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=26
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=25
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_ChancePrecip=60
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_ChanceSnow=51
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_RelHumidity=81
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_WindSpeedMPH=3
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_WindSpeedKM=5
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_WindSpeedKN=3
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=19
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=20
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_WindDegrees=74
1/16/2011 8:28:57 AM   System   SetVariable   music_CurrentPosition_3=02:50
1/16/2011 8:28:57 AM   Conditional   Server   Event Triggered for Whenever music_currentposition_3 changes value
1/16/2011 8:28:57 AM   Conditional   Server           Then SetVariable|music_CurrentPosition_CHA5~{{music_CurrentPosition_3}}
1/16/2011 8:28:57 AM   Push [523]      SetVariable|music_CurrentPosition_CHA5~{{music_CurrentPosition_3}}
1/16/2011 8:28:57 AM   PING   kitchen   Ping to kitchen.
1/16/2011 8:28:57 AM   PING   Laptop   Ping to Laptop.
1/16/2011 8:28:57 AM   PING   basement   Ping to basement.
1/16/2011 8:28:57 AM   System   SetVariable   music_CurrentPercent_3=69
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=38
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=26
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_WindDirection=ENE
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_HeatIndexF=25
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_HeatIndexC=-3
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_WindChillF=21
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_WindChillC=-6
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_VisibilityMI=2
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=41
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=34
1/16/2011 8:28:57 AM   Client   kitchen   kitchen sent [Q]
1/16/2011 8:28:57 AM   Client   Laptop   Laptop sent [Q]
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_VisibilityKM=3
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_CloudCoverage=89
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_DewPointF=21
1/16/2011 8:28:57 AM   Client   basement   basement sent [Q]
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_DewPointC=-6
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=21
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=16
1/16/2011 8:28:57 AM   System   SetVariable   192.168.1.160_timer01_time=-1
1/16/2011 8:28:57 AM   System   SetVariable   192.168.1.160_timer01_timeHMS=00:-1
1/16/2011 8:28:57 AM   System   SetVariable   192.168.1.160_timer_MLRSS_Next_Item_time=-1
1/16/2011 8:28:57 AM   System   SetVariable   192.168.1.160_timer_MLRSS_Next_Item_timeHMS=00:-1
1/16/2011 8:28:57 AM   System   SetVariable   MLTimer_timer01_time=-1
1/16/2011 8:28:57 AM   System   SetVariable   MLTimer_timer01_timeHMS=00:-1
1/16/2011 8:28:57 AM   System   SetVariable   MLTimer_timer_MLRSS_Next_Item_time=-1
1/16/2011 8:28:57 AM   System   SetVariable   MLTimer_timer_MLRSS_Next_Item_timeHMS=00:-1
1/16/2011 8:28:57 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:57 AM   MLProcess   Server   Loopback at level 2
1/16/2011 8:28:57 AM   Processing (2)      MLServeCmd.Macro|MLRSS|NextItem~{{mlrss_active_feed_number}}!RSS_Photo
1/16/2011 8:28:57 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:57 AM   MLProcess   Server   Loopback at level 3
1/16/2011 8:28:57 AM   Processing (3)      MLRSS|NextItem~{{mlrss_active_feed_number}}
1/16/2011 8:28:57 AM   MLProcess   Server   Calling doCommand in MLRSS
1/16/2011 8:28:57 AM   Subst In      NextItem~{{mlrss_active_feed_number}}
1/16/2011 8:28:57 AM   Subst Out      NextItem~1
1/16/2011 8:28:57 AM   System   SetVariable   MLRss_active_feed_item_title=Horoscope Hang-Up: Earth Rotation Changes Zodiac Signs
    (Time.com)
1/16/2011 8:28:57 AM   System   SetVariable   MLRss_active_feed_item_link=http://us.rd.yahoo.com/dailynews/rss/us/*http://us.rd.yahoo.com/dailynews/external/time_rss/rss_time_us/httpnewsfeedtimecom20110113horoscopehangupearthrotationchangeszodiacsignsxidrssnationyahoo/39643227/SIG=13hdt23a9/*http://newsfeed.time.com/2011/01/13/horoscope-hang-up-earth-rotation-changes-zodiac-signs/?xid=rss-nation-yahoo
1/16/2011 8:28:57 AM   System   SetVariable   MLRss_active_feed_item_description=Time.com - If you're the type of person who relies on mysterious-sounding locations of stars to determine your personality and outcome in life, get ready to be shocked
1/16/2011 8:28:57 AM   System   SetVariable   MLRss_active_feed_item_count=4 of 20
1/16/2011 8:28:57 AM   MLProcess   Server   Returned from MLRSS doCommand call
1/16/2011 8:28:57 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:57 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:57 AM   MLProcess   Server   Loopback at level 3
1/16/2011 8:28:57 AM   Processing (3)      RSS_Photo
1/16/2011 8:28:57 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:57 AM   MLProcess   Server   Loopback at level 4
1/16/2011 8:28:57 AM   Processing (4)      Macro|MLStrings|InStr~mlrss_active_feed_item_image~{{mlrss_active_feed_item_description}}~yimg!MLMath|Subtract~mlrss_active_feed_item_imagestart~{{mlrss_active_feed_item_image}}~9!MLStrings|InStr~mlrss_active_feed_item_image~{{mlrss_active_feed_item_description}}~jpg!MLMath|Add~mlrss_active_feed_item_imageend~{{mlrss_active_feed_item_image}}~3!MLMath|Subtract~mlrss_active_feed_item_imagelength~{{mlrss_active_feed_item_imageend}}~{{mlrss_active_feed_item_imagestart}}!MLStrings|Mid~mlrss_active_feed_item_imageurl~{{mlrss_active_feed_item_description}}~{{mlrss_active_feed_item_imagestart}}~{{mlrss_active_feed_item_imagelength}}
1/16/2011 8:28:57 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:57 AM   MLProcess   Server   Loopback at level 5
1/16/2011 8:28:57 AM   Processing (5)      MLStrings|InStr~mlrss_active_feed_item_image~{{mlrss_active_feed_item_description}}~yimg
1/16/2011 8:28:57 AM   MLProcess   Server   Calling doCommand in MLStrings
1/16/2011 8:28:57 AM   Subst In      InStr~mlrss_active_feed_item_image~{{mlrss_active_feed_item_description}}~yimg
1/16/2011 8:28:57 AM   Subst Out      InStr~mlrss_active_feed_item_image~Time.com - If you're the type of person who relies on mysterious-sounding locations of stars to determine your personality and outcome in life, get ready to be shocked~yimg
1/16/2011 8:28:57 AM   System   SetVariable   mlrss_active_feed_item_image=0
1/16/2011 8:28:57 AM   MLProcess   Server   Returned from MLStrings doCommand call
1/16/2011 8:28:57 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:57 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:57 AM   MLProcess   Server   Loopback at level 5
1/16/2011 8:28:57 AM   Processing (5)      MLMath|Subtract~mlrss_active_feed_item_imagestart~{{mlrss_active_feed_item_image}}~9
1/16/2011 8:28:57 AM   MLProcess   Server   Calling doCommand in MLMath
1/16/2011 8:28:57 AM   Subst In      Subtract~mlrss_active_feed_item_imagestart~{{mlrss_active_feed_item_image}}~9
1/16/2011 8:28:57 AM   Subst Out      Subtract~mlrss_active_feed_item_imagestart~0~9
1/16/2011 8:28:57 AM   System   SetVariable   mlrss_active_feed_item_imagestart=-9
1/16/2011 8:28:57 AM   MLProcess   Server   Returned from MLMath doCommand call
1/16/2011 8:28:57 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:57 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:57 AM   MLProcess   Server   Loopback at level 5
1/16/2011 8:28:57 AM   Processing (5)      MLStrings|InStr~mlrss_active_feed_item_image~{{mlrss_active_feed_item_description}}~jpg
1/16/2011 8:28:57 AM   MLProcess   Server   Calling doCommand in MLStrings
1/16/2011 8:28:57 AM   Subst In      InStr~mlrss_active_feed_item_image~{{mlrss_active_feed_item_description}}~jpg
1/16/2011 8:28:57 AM   Subst Out      InStr~mlrss_active_feed_item_image~Time.com - If you're the type of person who relies on mysterious-sounding locations of stars to determine your personality and outcome in life, get ready to be shocked~jpg
1/16/2011 8:28:57 AM   System   SetVariable   mlrss_active_feed_item_image=0
1/16/2011 8:28:57 AM   MLProcess   Server   Returned from MLStrings doCommand call
1/16/2011 8:28:57 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:57 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:57 AM   MLProcess   Server   Loopback at level 5
1/16/2011 8:28:57 AM   Processing (5)      MLMath|Add~mlrss_active_feed_item_imageend~{{mlrss_active_feed_item_image}}~3
1/16/2011 8:28:57 AM   MLProcess   Server   Calling doCommand in MLMath
1/16/2011 8:28:57 AM   Subst In      Add~mlrss_active_feed_item_imageend~{{mlrss_active_feed_item_image}}~3
1/16/2011 8:28:57 AM   Subst Out      Add~mlrss_active_feed_item_imageend~0~3
1/16/2011 8:28:57 AM   System   SetVariable   mlrss_active_feed_item_imageend=3
1/16/2011 8:28:57 AM   MLProcess   Server   Returned from MLMath doCommand call
1/16/2011 8:28:57 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:57 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:57 AM   MLProcess   Server   Loopback at level 5
1/16/2011 8:28:57 AM   Processing (5)      MLMath|Subtract~mlrss_active_feed_item_imagelength~{{mlrss_active_feed_item_imageend}}~{{mlrss_active_feed_item_imagestart}}
1/16/2011 8:28:57 AM   MLProcess   Server   Calling doCommand in MLMath
1/16/2011 8:28:57 AM   Subst In      Subtract~mlrss_active_feed_item_imagelength~{{mlrss_active_feed_item_imageend}}~{{mlrss_active_feed_item_imagestart}}
1/16/2011 8:28:57 AM   Subst Out      Subtract~mlrss_active_feed_item_imagelength~3~-9
1/16/2011 8:28:57 AM   System   SetVariable   mlrss_active_feed_item_imagelength=12
1/16/2011 8:28:57 AM   MLProcess   Server   Returned from MLMath doCommand call
1/16/2011 8:28:57 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:57 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:57 AM   MLProcess   Server   Loopback at level 5
1/16/2011 8:28:57 AM   Processing (5)      MLStrings|Mid~mlrss_active_feed_item_imageurl~{{mlrss_active_feed_item_description}}~{{mlrss_active_feed_item_imagestart}}~{{mlrss_active_feed_item_imagelength}}
1/16/2011 8:28:57 AM   MLProcess   Server   Calling doCommand in MLStrings
1/16/2011 8:28:57 AM   Subst In      Mid~mlrss_active_feed_item_imageurl~{{mlrss_active_feed_item_description}}~{{mlrss_active_feed_item_imagestart}}~{{mlrss_active_feed_item_imagelength}}
1/16/2011 8:28:57 AM   Subst Out      Mid~mlrss_active_feed_item_imageurl~Time.com - If you're the type of person who relies on mysterious-sounding locations of stars to determine your personality and outcome in life, get ready to be shocked~-9~12
1/16/2011 8:28:57 AM   System   SetVariable   mlrss_active_feed_item_imageurl=
1/16/2011 8:28:57 AM   Conditional   Server   Event Triggered for Whenever mlrss_active_feed_item_imageurl changes value
1/16/2011 8:28:57 AM   Conditional   Server       And mlrss_active_feed_item_imageurl is blank
1/16/2011 8:28:57 AM   Conditional   Server           Then SetVariable|mlrss_active_feed_item_imageurl~images\news.jpg
1/16/2011 8:28:57 AM   Push [524]      SetVariable|mlrss_active_feed_item_imageurl~images\news.jpg
1/16/2011 8:28:57 AM   MLProcess   Server   Returned from MLStrings doCommand call
1/16/2011 8:28:57 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:57 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:57 AM   MLProcess   Server   Exit via command map
1/16/2011 8:28:57 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:57 AM   System   SetVariable   192.168.1.160_timer01_state=1
1/16/2011 8:28:57 AM   System   SetVariable   192.168.1.160_timer_MLRSS_Next_Item_state=1
1/16/2011 8:28:57 AM   System   SetVariable   MLTimer_timer01_state=1
1/16/2011 8:28:57 AM   System   SetVariable   music_CurrentPosition_3=02:50
1/16/2011 8:28:57 AM   System   SetVariable   music_CurrentPercent_3=70
1/16/2011 8:28:57 AM   System   SetVariable   MLTimer_timer_MLRSS_Next_Item_state=1
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=28
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=16
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=25
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=28
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=29
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=31
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=29
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=28
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=26
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=23
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=33
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=34
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_UVIndex=0
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_UVDescr=Low
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=35
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=35
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF46_UVWarn=0
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF47_Hour=47
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF_ReportTime=1/16/2011 8:04:41 am
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF_ReportTimeYear=2011
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF_ReportTimeMonth=1
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF_ReportTimeDay=16
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF_ReportTimeHour=8
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF_ReportTimeMinute=04
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF_ReportTimeSecond=41
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF_ReportTimeAmPm=AM
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF_ReportTimeDOW=Sunday
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=17
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=18
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuleft_3=29
1/16/2011 8:28:57 AM   System   SetVariableClient   music_vuright_3=30
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF47_DOW=Tuesday
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF47_DateUTC=1/18/2011 12 pm
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF47_Date=1/18/2011 7 am
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF47_Time=7 am
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF47_DateYear=2011
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF47_DateMonth=1
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF47_DateDay=18
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF47_DateHour=7
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF47_DateMinute=00
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF47_DateSecond=00
1/16/2011 8:28:57 AM   System   SetVariableFast   MLWeather_HF47_DateAmPm=AM
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_DateDOW=Tuesday
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_NewDate=
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=19
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=22
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=17
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=19
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_TempF=26
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_TempC=-3
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_SkyCode=14
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=18
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=23
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_SkyCodeExt=1400
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_Icon=74
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_SkyL=Snow Showers
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_SkyM=Snow Showers
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_SkyS=Snow Showers
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=41
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=32
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_ChancePrecip=60
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_ChanceSnow=50
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_RelHumidity=90
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_WindSpeedMPH=3
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_WindSpeedKM=5
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=38
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=32
1/16/2011 8:28:58 AM   System   SetVariable   music_CurrentPosition_3=02:51
1/16/2011 8:28:58 AM   Conditional   Server   Event Triggered for Whenever music_currentposition_3 changes value
1/16/2011 8:28:58 AM   Conditional   Server           Then SetVariable|music_CurrentPosition_CHA5~{{music_CurrentPosition_3}}
1/16/2011 8:28:58 AM   Push [525]      SetVariable|music_CurrentPosition_CHA5~{{music_CurrentPosition_3}}
1/16/2011 8:28:58 AM   System   SetVariable   music_CurrentPercent_3=70
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_WindSpeedKN=3
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_WindDegrees=77
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=32
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=20
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_WindDirection=ENE
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_HeatIndexF=26
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_HeatIndexC=-3
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_WindChillF=23
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_WindChillC=-5
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_VisibilityMI=2
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=36
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=27
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_VisibilityKM=3
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_CloudCoverage=88
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_DewPointF=24
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_DewPointC=-4
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_UVIndex=0
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=39
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=35
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_UVDescr=Low
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF47_UVWarn=0
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_Hour=48
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF_ReportTime=1/16/2011 8:04:41 am
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF_ReportTimeYear=2011
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF_ReportTimeMonth=1
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF_ReportTimeDay=16
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF_ReportTimeHour=8
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF_ReportTimeMinute=04
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF_ReportTimeSecond=41
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF_ReportTimeAmPm=AM
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF_ReportTimeDOW=Sunday
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=38
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=40
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=34
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=32
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_DOW=Tuesday
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_DateUTC=1/18/2011 1 pm
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_Date=1/18/2011 8 am
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_Time=8 am
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_DateYear=2011
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_DateMonth=1
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_DateDay=18
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_DateHour=8
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_DateMinute=00
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_DateSecond=00
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_DateAmPm=AM
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_DateDOW=Tuesday
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_NewDate=
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=33
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=31
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=32
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=32
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_TempF=29
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_TempC=-1
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=21
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=27
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_SkyCode=14
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_SkyCodeExt=1400
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_Icon=74
1/16/2011 8:28:58 AM   System   SetVariable   music_CurrentPosition_3=02:51
1/16/2011 8:28:58 AM   System   SetVariable   music_CurrentPercent_3=70
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=35
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=26
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_SkyL=Snow Showers
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_SkyM=Snow Showers
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_SkyS=Snow Showers
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_ChancePrecip=70
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_ChanceSnow=54
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=39
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=37
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_RelHumidity=90
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_WindSpeedMPH=4
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_WindSpeedKM=6
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_WindSpeedKN=3
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_WindDegrees=78
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_WindDirection=ENE
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=44
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=35
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_HeatIndexF=29
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_HeatIndexC=-1
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_WindChillF=25
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_WindChillC=-3
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_VisibilityMI=2
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuleft_3=31
1/16/2011 8:28:58 AM   System   SetVariableClient   music_vuright_3=29
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_VisibilityKM=3
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_CloudCoverage=87
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_DewPointF=27
1/16/2011 8:28:58 AM   System   SetVariableFast   MLWeather_HF48_DewPointC=-2
1/16/2011 8:28:58 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:58 AM   MLProcess   Server   Loopback at level 2
1/16/2011 8:28:58 AM   Processing (2)      MLServeCMD.Macro|SetVariable|MLHSPlugin_O97~Mon-Sat!SetVariable|MLHSPlugin_Wiring Closet Audio Tuner A PSN~Mon-Sat
1/16/2011 8:28:58 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:58 AM   MLProcess   Server   Loopback at level 3
1/16/2011 8:28:58 AM   Processing (3)      SetVariable|MLHSPlugin_O97~Mon-Sat
1/16/2011 8:28:58 AM   System   SetVariable   MLHSPlugin_O97=Mon-Sat
1/16/2011 8:28:59 AM   Conditional   Server   Event Triggered for Whenever mlhsplugin_o97 changes value
1/16/2011 8:28:59 AM   Conditional   Server           Then SetVariable|music_currentartistname_CHA1~{{MLHSPlugin_o97}}
1/16/2011 8:28:59 AM   Push [526]      SetVariable|music_currentartistname_CHA1~{{MLHSPlugin_o97}}
1/16/2011 8:28:59 AM   System   SetVariable   192.168.1.160_timer10_time=-1
1/16/2011 8:28:59 AM   System   SetVariable   192.168.1.160_timer10_timeHMS=00:-1
1/16/2011 8:28:59 AM   System   SetVariable   192.168.1.160_timer_SecurityCamera_time=-1
1/16/2011 8:28:59 AM   System   SetVariable   192.168.1.160_timer_SecurityCamera_timeHMS=00:-1
1/16/2011 8:28:59 AM   System   SetVariable   MLTimer_timer10_time=-1
1/16/2011 8:28:59 AM   System   SetVariable   MLTimer_timer10_timeHMS=00:-1
1/16/2011 8:28:59 AM   System   SetVariable   MLTimer_timer_SecurityCamera_time=-1
1/16/2011 8:28:59 AM   System   SetVariable   MLTimer_timer_SecurityCamera_timeHMS=00:-1
1/16/2011 8:28:59 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:59 AM   MLProcess   Server   Loopback at level 4
1/16/2011 8:28:59 AM   Processing (4)      MLServeCmd.Macro|MLCycleStates|Next~Security_Camera!
1/16/2011 8:28:59 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:59 AM   MLProcess   Server   Loopback at level 5
1/16/2011 8:28:59 AM   Processing (5)      MLCycleStates|Next~Security_Camera
1/16/2011 8:28:59 AM   MLProcess   Server   Calling doCommand in MLCycleStates
1/16/2011 8:28:59 AM   System   SetVariable   _Security_Camera_Data=2
1/16/2011 8:28:59 AM   System   SetVariable   _Security_Camera_Label=Basement - By Windows
1/16/2011 8:28:59 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:59 AM   MLProcess   Server   Loopback at level 6
1/16/2011 8:28:59 AM   Processing (6)      MLServeCmd.Macro|SetVariable|Security_Camera_Active~2
1/16/2011 8:28:59 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:59 AM   MLProcess   Server   Loopback at level 7
1/16/2011 8:28:59 AM   Processing (7)      SetVariable|Security_Camera_Active~2
1/16/2011 8:28:59 AM   System   SetVariable   Security_Camera_Active=2
1/16/2011 8:28:59 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:59 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:59 AM   MLProcess   Server   Returned from MLCycleStates doCommand call
1/16/2011 8:28:59 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:59 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:59 AM   MLProcess   Server   Loopback at level 5
1/16/2011 8:28:59 AM   Processing (5)      
1/16/2011 8:28:59 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:59 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:59 AM   System   SetVariable   192.168.1.160_timer10_state=1
1/16/2011 8:28:59 AM   System   SetVariable   192.168.1.160_timer_SecurityCamera_state=1
1/16/2011 8:28:59 AM   System   SetVariable   MLTimer_timer10_state=1
1/16/2011 8:28:59 AM   System   SetVariable   MLTimer_timer_SecurityCamera_state=1
1/16/2011 8:28:59 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:59 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:59 AM   MLProcess   Server   Loopback at level 3
1/16/2011 8:28:59 AM   Processing (3)      SetVariable|MLHSPlugin_Wiring Closet Audio Tuner A PSN~Mon-Sat
1/16/2011 8:28:59 AM   System   SetVariable   MLHSPlugin_Wiring Closet Audio Tuner A PSN=Mon-Sat
1/16/2011 8:28:59 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:59 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:59 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:59 AM   MLProcess   Server   Loopback at level 2
1/16/2011 8:28:59 AM   Processing (2)      MLServeCMD.Macro|SetVariable|MLHSPlugin_O97_LastChanged~1/16/2011 8:29:03 AM!SetVariable|MLHSPlugin_Wiring Closet Audio Tuner A PSN_LastChanged~1/16/2011 8:29:03 AM
1/16/2011 8:28:59 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:59 AM   MLProcess   Server   Loopback at level 3
1/16/2011 8:28:59 AM   Processing (3)      SetVariable|MLHSPlugin_O97_LastChanged~1/16/2011 8:29:03 AM
1/16/2011 8:28:59 AM   System   SetVariable   MLHSPlugin_O97_LastChanged=1/16/2011 8:29:03 AM
1/16/2011 8:28:59 AM   System   SetVariable   music_CurrentPosition_3=02:52
1/16/2011 8:28:59 AM   Conditional   Server   Event Triggered for Whenever music_currentposition_3 changes value
1/16/2011 8:28:59 AM   Conditional   Server           Then SetVariable|music_CurrentPosition_CHA5~{{music_CurrentPosition_3}}
1/16/2011 8:28:59 AM   Push [527]      SetVariable|music_CurrentPosition_CHA5~{{music_CurrentPosition_3}}
1/16/2011 8:28:59 AM   System   SetVariable   music_CurrentPercent_3=70
1/16/2011 8:28:59 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:59 AM   MLProcess   Server   Entered MLProcess.
1/16/2011 8:28:59 AM   MLProcess   Server   Loopback at level 3
1/16/2011 8:28:59 AM   Processing (3)      SetVariable|MLHSPlugin_Wiring Closet Audio Tuner A PSN_LastChanged~1/16/2011 8:29:03 AM
1/16/2011 8:28:59 AM   System   SetVariable   MLHSPlugin_Wiring Closet Audio Tuner A PSN_LastChanged=1/16/2011 8:29:03 AM
1/16/2011 8:28:59 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:59 AM   MLProcess   Server   Exiting MLProcess
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=34
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=32
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=28
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=35
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=29
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=29
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=34
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=30
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=30
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=22
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=38
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=35
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_HF48_UVIndex=0
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_HF48_UVDescr=Low
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=38
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=25
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_HF48_UVWarn=0
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_Day=1
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_DateUTC=1/16/2011 12:00:00 AM
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_Date=1/16/2011 7:00:00 am
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_DateYear=2011
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_DateMonthNum=1
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_DateMonth=Jan
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_date=Jan 16
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_DateDay=16
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_DateHour=7
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_DateMinute=00
1/16/2011 8:28:59 AM   System   SetVariable   192.168.1.160_timer02_time=50
1/16/2011 8:28:59 AM   System   SetVariable   192.168.1.160_timer02_timeHMS=00:50
1/16/2011 8:28:59 AM   System   SetVariable   192.168.1.160_timer_MLRSS_Next_Feed_time=50
1/16/2011 8:28:59 AM   System   SetVariable   192.168.1.160_timer_MLRSS_Next_Feed_timeHMS=00:50
1/16/2011 8:28:59 AM   System   SetVariable   MLTimer_timer02_time=50
1/16/2011 8:28:59 AM   System   SetVariable   MLTimer_timer02_timeHMS=00:50
1/16/2011 8:28:59 AM   System   SetVariable   MLTimer_timer_MLRSS_Next_Feed_time=50
1/16/2011 8:28:59 AM   System   SetVariable   MLTimer_timer_MLRSS_Next_Feed_timeHMS=00:50
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_DateSecond=00
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_DateAMPM=AM
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_DateDOW=Sunday
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_day=Sunday
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=33
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=29
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=31
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=29
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=34
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=46
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=33
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=30
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_HiTempF=33
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_hitemp=33
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_LoTempF=4
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_lowtemp=4
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=23
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=30
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_HiTempC=0
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_LoTempC=-15
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_DayShort=Mix of sun and clouds
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_day_description=Mix of sun and clouds
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_current_condition=Mix of sun and clouds
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=29
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=35
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_Day=Sunshine and clouds mixed. High 33F. Winds WNW at 10 to 20 mph.
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_current_description=Sunshine and clouds mixed. High 33F. Winds WNW at 10 to 20 mph.
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_Night=Mostly clear. Low 4F. Winds NW at 5 to 10 mph.
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_night_description=Mostly clear. Low 4F. Winds NW at 5 to 10 mph.
1/16/2011 8:28:59 AM   System   SetVariable   music_CurrentPosition_3=02:53
1/16/2011 8:28:59 AM   Conditional   Server   Event Triggered for Whenever music_currentposition_3 changes value
1/16/2011 8:28:59 AM   Conditional   Server           Then SetVariable|music_CurrentPosition_CHA5~{{music_CurrentPosition_3}}
1/16/2011 8:28:59 AM   Push [528]      SetVariable|music_CurrentPosition_CHA5~{{music_CurrentPosition_3}}
1/16/2011 8:28:59 AM   System   SetVariable   music_CurrentPercent_3=71
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=41
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=44
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_Icon=66
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_day_icon=http://192.168.1.160:6246/Images/MLWeather/wx_66.swf
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_day_iconimage=http://192.168.1.160:6246/Images/MLWeather/wx_66.png
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_night_icon=http://192.168.1.160:6246/Images/MLWeather/wx_66.swf
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_night_iconimage=http://192.168.1.160:6246/Images/MLWeather/wx_66.png
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=34
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=35
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_SkyCode=30
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_SkyText=Partly Cloudy
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_ChancePrecip=10
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_day_precipitation=10
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_night_precipitation=10
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuleft_3=24
1/16/2011 8:28:59 AM   System   SetVariableClient   music_vuright_3=26
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_ChanceSnow=10
1/16/2011 8:28:59 AM   System   SetVariableFast   MLWeather_DF1_RelHumidity=41
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_day_humidity=41
1/16/2011 8:28:59 AM   System   SetVariableFast   mlweather_forecast_1_night_humidity=41
1/16/2011 8:29:00 AM   System   SetVariableClient   music_vuleft_3=31
1/16/2011 8:29:00 AM   System   SetVariableClient   music_vuright_3=31
1/16/2011 8:29:00 AM   System   SetVariableFast   MLWeather_DF1_WindSpeedMPH=13
1/16/2011 8:29:00 AM   System   SetVariableFast   mlweather_forecast_1_day_wind_speed=13
1/16/2011 8:29:05 AM   Client   basement   basement sent [Q]
1/16/2011 8:29:05 AM   Client   kitchen   kitchen sent [Q]
1/16/2011 8:29:05 AM   Client   Laptop   Laptop sent [Q]
1/16/2011 8:29:10 AM   Client   kitchen   kitchen sent [Q]
1/16/2011 8:29:10 AM   Client   Laptop   Laptop sent [Q]
1/16/2011 8:29:10 AM   Client   basement   basement sent [Q]
Simon D. S. Mason

User avatar
DaveB
Simply Incredible
Simply Incredible
Posts: 3143
Joined: Sun May 30, 2004 10:57 pm
Location: Mays Landing, NJ
Contact:

Re: How to diagnose MLServer performance issue?

Postby DaveB » Sun Jan 16, 2011 9:36 am

The next time you have this issue, look at MLWorker Agent and see if there is a huge backlog of items. Sometimes the weather data, particularly for maps, gets slow. Also, I have had an issue with other data like album and song info.
Thanks!

Dave Bruner
:shock:

User avatar
CinemarDave
Site Admin
Site Admin
Posts: 10535
Joined: Fri Feb 07, 2003 8:56 am
Location: Planet Earth
Contact:

Re: How to diagnose MLServer performance issue?

Postby CinemarDave » Mon Jan 17, 2011 2:43 pm

You have some lengthy macros running that are recursive in nature. See the looping at level 5 message. That means that you are at least 5 levels deep in macros calling macros. Not really an issue but something that could perhaps be simplified. Also during that time you were subject to a MLWeather update. This kicked in a process that updated several thousand server variables. Also in the background you are playing music and using the VU Meters. This hits MLServer with several thousand server variable updates per minute per music zone that is active. That's the SetVariableClient commands in the log.

Serveral things to look at here. MLServer is capable of handling all that work. But do you have enough CPU horsepower? What is your Network bandwidth? Using a gigabit home network is ideal. 100 mbit is great. 10 mb is slow. Is your MLServer using a hardwired connection? Any wireless clients? What network speed is your slowest wireless client? I'm asking all these networking questions because I feel you have a network bottleneck that is causing MLServer to not run as fast as it could.

The worker agent really doesn't come into play here since it is a standalone program. While it can consume CPU in this case something is constipating MLServer.

bigDvette
Expert
Expert
Posts: 718
Joined: Thu Oct 12, 2006 12:19 pm
Contact:

Re: How to diagnose MLServer performance issue?

Postby bigDvette » Mon Jan 17, 2011 3:33 pm

Simon, what are you running MLServer on? Is it a standalone box, a home server (WHS) ...

User avatar
simonmason
Expert
Expert
Posts: 855
Joined: Tue Dec 26, 2006 9:06 pm
Contact:

Re: How to diagnose MLServer performance issue?

Postby simonmason » Tue Jan 18, 2011 9:19 am

I am running MLServer on a dedicated purpose built machine that I put together a few years ago. It is a Pentium Dual Core E5200 (2.5 GHz). It is running Windows XP Professional. I just realized I have 1 GB of RAM in it - so presumably a simple thing to improve performance might be to increase the RAM?

As for the macros. Can you help point me to something specific so I can see what code/events are creating this situation? Thanks.
Simon D. S. Mason

User avatar
CinemarDave
Site Admin
Site Admin
Posts: 10535
Joined: Fri Feb 07, 2003 8:56 am
Location: Planet Earth
Contact:

Re: How to diagnose MLServer performance issue?

Postby CinemarDave » Tue Jan 18, 2011 11:46 am

More memory will help. But you didn't answer my network questions. I'd worry about that before I'd worry about what the macros are doing.

User avatar
simonmason
Expert
Expert
Posts: 855
Joined: Tue Dec 26, 2006 9:06 pm
Contact:

Re: How to diagnose MLServer performance issue?

Postby simonmason » Tue Jan 18, 2011 1:11 pm

Currently is hooked up via 100MB directly into a hub that is connected to my Verizon Fios Router (both with short cables - they are located in the same equipment closet). The hub is gigabit. I purchased a gigabit card for the server but had some driver issues with it so have not finished the installation. I can focus on installing the gigabit card - will it make a significant difference?
Simon D. S. Mason

User avatar
CinemarDave
Site Admin
Site Admin
Posts: 10535
Joined: Fri Feb 07, 2003 8:56 am
Location: Planet Earth
Contact:

Re: How to diagnose MLServer performance issue?

Postby CinemarDave » Tue Jan 18, 2011 1:55 pm

Installing a gigabit backbone is the best first start. You want to stay away from hubs whenever possible and go with switches. When you have everything connected to a hub all the devices connected to it see all the network traffic going through the hub. This can cause your entire network to bog down. Switches isolate the network traffic so that each device only sees the network traffic that it needs to.

User avatar
simonmason
Expert
Expert
Posts: 855
Joined: Tue Dec 26, 2006 9:06 pm
Contact:

Re: How to diagnose MLServer performance issue?

Postby simonmason » Tue Jan 18, 2011 5:46 pm

Sorry, I should have been clearer. They are switches. I have two of them strung together at both ends of the house and they are reporting that they are operating at gigabit speeds. I am slowly moving through the machines and switching them to gigabit adaptors.
Simon D. S. Mason

User avatar
simonmason
Expert
Expert
Posts: 855
Joined: Tue Dec 26, 2006 9:06 pm
Contact:

Re: How to diagnose MLServer performance issue?

Postby simonmason » Thu Jan 20, 2011 9:05 pm

I installed the Gigabit Ethernet the other day and I am still experiencing performance issues. I have one touchscreen in my kitchen and one in the basement. Neither of these seem to cause the issue. I have a laptop that I use to program and it only seems to occur when I am connecting from this client. I often have pcAnywhere open so I can see things on the server and I am wondering if this is causing a problem? Any other thoughts on how to diagnose this? Thanks.
Simon D. S. Mason

bigDvette
Expert
Expert
Posts: 718
Joined: Thu Oct 12, 2006 12:19 pm
Contact:

Re: How to diagnose MLServer performance issue?

Postby bigDvette » Fri Jan 21, 2011 12:16 am

Ok, this is going to sound really stup, but what level do you have your event log set at. i can tell you if you are logging at verbose levels (and sometimes informational), it will make your scenes sluggish.

Also, have you opened task manager and looked at perfmon to see what is taking up CPU or I/O if that is the problem.

lastly, go through all your plugins and make sure logging is not turned on for the plugin.

User avatar
simonmason
Expert
Expert
Posts: 855
Joined: Tue Dec 26, 2006 9:06 pm
Contact:

Re: How to diagnose MLServer performance issue?

Postby simonmason » Fri Jan 21, 2011 7:33 am

I usually have logging on error only. I do watch the Task Manager and the machine doesn't seem to show much else going on when this condition occurs. There are some other things running on it but they seem to be close to zero most of the time when this is happening.

You got me thinking about the plugins. I generally load these to play around with and then leave them enabled even if I don't use them.
I went through the list and disabled a bunch of plugins that I am not using. I am not sure if this will do anything as I am not using them but presumably this reduces the overhead needed?
Simon D. S. Mason

bigDvette
Expert
Expert
Posts: 718
Joined: Thu Oct 12, 2006 12:19 pm
Contact:

Re: How to diagnose MLServer performance issue?

Postby bigDvette » Fri Jan 21, 2011 10:13 am

Did you look at the event tab on all of your plugins. For instance, for a long time my music lobby was logging and dragging down the system a bit. This has nothing to do with your event manager log level.


Return to “MLServer 3”

Who is online

Users browsing this forum: No registered users and 1 guest