Gammon Forum : MUSHclient : Suggestions : Adding tenths and hundreths of a second to logging

Entire forum ➜ MUSHclient ➜ Suggestions ➜ Adding tenths and hundreths of a second to logging

Adding tenths and hundreths of a second to logging

It is now over 60 days since the last post. This thread is closed. Refresh page

Posted by

Batista (15 posts) Bio

Date

Sat 31 Dec 2005 12:03 PM (UTC)

Message

The logging features of MUSHclient are amazing already. Logging in seconds helps a lot with timing my attacks, balances, and whatever else. However, sometimes I need to test the speed of weapons, and that means I have to check the miliseconds.

Is it possible to add this feature into MUSH? Or is it in already and I don't know? I checked Flannel's script on this thing, but it's not very practical. I'd like to be able to log in my spars and duels. Having my triggers disabled isn't fun.

I was thinking maybe have a logging flag thingy that'll let you display time like: HRS:MINS:SEC.TIMEtoTWOorTHREEplaces.

Just a small suggestion. Other than that, the logging is absolute perfection.

Top

Posted by

Nick Gammon Australia (23,140 posts) Bio Forum Administrator

Date

Reply #1 on Sat 31 Dec 2005 07:48 PM (UTC)

Message

I'm not totally sure how practical that is, with network lag at, say, 0.5 seconds, you may find a millisecond timer would confuse you with inaccurate readings.

The trouble is, it isn't that easy to do. Most of the timers in Windows are to a second granularity, and thus the date/time formatting used in the logging only offers seconds. In fact that is a call to a "library" function which I didn't write. If I changed that I would have to do quite a bit of extra code.

What you could do it do your own logging, and in the script use GetInfo (232) to find the high-performance timer figure, which is a floating-point number that should be very accurate. However you then need to convert that into a date/time.

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Top

Posted by

Tsunami USA (204 posts) Bio

Date

Reply #2 on Mon 02 Jan 2006 07:01 PM (UTC)

Message

Without looking at the documentation or anything, I'm assuming GetInfo(232) returns the timestamp? Simple subtraction should suffice then, since its really only the difference in time I ever require, not the actual time.

Top

Posted by

Batista (15 posts) Bio

Date

Reply #3 on Mon 02 Jan 2006 10:31 PM (UTC)

Message

Hmm... how do I interpret this, exactly? If you can tell me that, I think I could probably figure out how to play around with it.

By the way, thanks for pointing that out to me!

Top

Posted by

Nick Gammon Australia (23,140 posts) Bio Forum Administrator

Date

Reply #4 on Tue 03 Jan 2006 12:52 AM (UTC)

Message

Interpret? Well, if you make a trigger that matches everything (eg. match on *) and "send to script", then you could write to the log file with your own preamble. You could use GetInfo (232) to find the number of seconds in the timer, and subtract each line from the previous line to get the difference.

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Top

Posted by

Batista (15 posts) Bio

Date

Reply #5 on Tue 03 Jan 2006 03:11 AM (UTC)

Message

Ok, so I should:

1.) Make a trigger to match on everything.
2.) Have it 'send to script'.

I'm confused what to do next. I am right now using the WriteLog function to send GetInfo(232) to script. However... my logs then read like a tax report.

I'd like to be able to have each line read something like:

[23.455] You slash into newbie.
[26.675] You have recovered balance.

Right now it reads more like:

3434h, 4343m -
6543420.43434341455
You slash into newbie.
6543423.23242342423
3434h, 4343m -
6543425.43532352542
You have recovered balance.
6543430.63237678346

I'm probably going to smack myself in the head and scream, "That was so simple!" after I make this post, but...

Any idea how to make this happen? Is there some way to put the value of GetInfo(232) into a preamble option for output in the logging options section?

Sorry for all the questions, but it's just one of the few things I've not been able to figure out on my own.

Top

Posted by

Batista (15 posts) Bio

Date

Reply #6 on Tue 03 Jan 2006 03:13 AM (UTC)

Message

Oh, and by 'interpret' I mean what the number in GetInfo(232) stands for and where it comes from.

Top

Posted by Nick Gammon Australia (23,140 posts) Bio Forum Administrator

Date

Reply #7 on Tue 03 Jan 2006 04:43 AM (UTC)

Amended on Tue 03 Jan 2006 04:48 AM (UTC) by Nick Gammon

Message

Quote:

However... my logs then read like a tax report.

Lol.

The info returned from GetInfo (232) is the internal timer, in seconds as a floating point number. It doesn't refer to any particular time. What you really want is the difference between each line. This trigger (written for Lua, but other languages would be similar) does that:


<triggers>
  <trigger
   enabled="y"
   keep_evaluating="y"
   match="^(.*)$"
   regexp="y"
   send_to="12"
   sequence="90"
  >
  <send>
if not previousTime then
  previousTime = GetInfo(232)
end -- first time through

-- time since last line
diff = GetInfo(232) - previousTime 

WriteLog (string.format ("[%.3f] ", diff), "%1")
</send>
  </trigger>
</triggers>

First time through, previousTime will be nil, so we set it to the current timer. That makes each subsequent line offset from when we starte logging. That cuts out the really big numbers before the decimal point.

Then we use %.3f in string.format to cut down the precision to only 3 decimal places. This gets rid of a lot more digits.

Then we use a single WriteLog to avoid the extra newline.

I gave it a sequence number of 90 to put it ahead of other triggers, and "keep evaluating" so other triggers would still be done. I also turned off "log output" in the general logging, as this trigger is doing it instead.

This is the sort of result I get:


[449.819] <1000hp 1000m 1000mv> 
[449.825] Vertic Avenue
[449.825] Nothing in particular strikes your attention as you walk down this portion
[449.825] of Vertic Avenue.  It seems almost as if the citizens of the city forgot
[449.825] to place a statue here, or perhaps a plaque.  The lengthy road ranges
[449.825] to the north and south.
[449.825] Exits: north south.
[449.825] 
[452.793] <1000hp 1000m 1000mv> 
[452.825] You are carrying:
[452.825]      Nothing.
[452.825]

These numbers are actually cumulative time since the start of logging.

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Top

Posted by Nick Gammon Australia (23,140 posts) Bio Forum Administrator

Date

Reply #8 on Tue 03 Jan 2006 04:48 AM (UTC)

Amended on Tue 03 Jan 2006 04:49 AM (UTC) by Nick Gammon

Message

Or, if you just want the difference between each line, use this version:


<triggers>
  <trigger
   enabled="y"
   keep_evaluating="y"
   match="^(.*)$"
   regexp="y"
   send_to="12"
   sequence="90"
  >
  <send>
if not previousTime then
  previousTime = GetInfo(232)
end -- first time through

-- time since last line
diff = GetInfo(232) - previousTime 

WriteLog (string.format ("[%.3f] ", diff), "%1")

-- save for next time
previousTime = GetInfo(232)
</send>
  </trigger>
</triggers>

This gives:


[0.032] Vertic Avenue
[0.000] Nothing in particular strikes your attention as you walk down this portion
[0.000] of Vertic Avenue.  It seems almost as if the citizens of the city forgot
[0.000] to place a statue here, or perhaps a plaque.  The lengthy road ranges
[0.000] to the north and south.
[0.000] Exits: north south.
[0.000] 
[1.892] <1000hp 1000m 1000mv> 
[0.107] You are carrying:
[0.000]      Nothing.
[0.000]

- Nick Gammon

www.gammon.com.au, www.mushclient.com

Top

The dates and times for posts above are shown in Universal Co-ordinated Time (UTC).

To show them in your local time you can join the forum, and then set the 'time correction' field in your profile to the number of hours difference between your location and UTC time.

23,840 views.

It is now over 60 days since the last post. This thread is closed. Refresh page

Go to topic: Search the forum

top