Profiles of Lua code

Tuesday, August 20, 2019

I started “Project: Sippy-Cup” six years ago as a “proof-of-concept” and it ended up in production (without my knowledge and to my dismay at the time) about a year or two afterwards. The code was written to be correct, not fast. And for the past four or five years its been running, performance has never been a real issue. But that's changing, as the projected traffic levels shoot past the “oh my” and into the “oh my God” territory.

“Project: Sippy-Cup” processes a lot of SIP messages, which are text based, so there's a lot of text processing. I use LPEG for ease of writing parsers, but it's not necessarily as fast as it could be.

There are two issues with LPEG—it has infinite look-ahead, and ordered choices. So the code that checks for the SIP method:

method = lpeg.P"ACK"
       + lpeg.P"BYE"
       + lpeg.P"CANCEL"
       + lpeg.P"INFO"
       + lpeg.P"INVITE"
       + lpeg.P"MESSAGE"
       + lpeg.P"NOTIFY"
       + lpeg.P"OPTIONS"
       + lpeg.P"PRACK"
       + lpeg.P"PUBLISH"
       + lpeg.P"REFER"
       + lpeg.P"REGISTER"
       + lpeg.P"SUBSCRIBE"
       + lpeg.P"UPDATE"
       + (lpeg.R("AZ","az","09") + lpeg.S"-.!%*_+`'~")^1

will first compare the input to “ACK”; if it doesn't match, it then backtracks and tries comparing the input to “BYE”, and so on down the list until it gets the last rule which is a “catch-all” rule. It would be easy to reorder the list so that the checks are “most-likely” to “least-likely,” but really the entire list could be removed leaving just the catch-all:

method = (lpeg.R("AZ","az","09") + lpeg.S"-.!%*_+`'~")^1

I have the same issue with SIP headers—there are 100 headers that are “parsed” (for various values of “parsed”) but I only really look at a dozen headers—the rest just slow things down and can be passed by a generic parsing rule. The full headers were added during the “proof-of-concept” stage since I wasn't sure at the time which headers would be critical and which ones wouldn't, and I've never gone back and cleaned up the code.

Another aspect is the sheer number of validity checks the code makes on the incoming SIP message. Many of the checks don't really have any effect on the processing due to managerial mandate at the time, so they could go (I wanted strict checking that bailed on any error; my manager at the time did not want such strictness—no need to guess who won, but I still track parsing irregularities).

So while I feel these are two areas where the code could be made faster, I don't know if that's where the time is spent, and so it's time to profile the code.

The issue now is that the system profiler will profile the code as C, not as Lua. I don't need to profile the code to know the Lua VM gets called all the time. What I need to know is what Lua code is called all the time. But it can't hurt to try the system profiler, right? And given that the regression test has over 12,000 test cases, we should get some good profiling information, right?

Original Profile—Each sample counts as 0.01 seconds.
% time	cumulative seconds	self seconds	name
13.32	3.47	3.47	`match`
12.74	6.79	3.32	`luaV_execute`
9.31	9.22	2.43	`luaS_newlstr`
6.83	11.00	1.78	`luaD_precall`
5.31	12.38	1.39	`luaH_getstr`
3.38	13.26	0.88	`luaD_poscall`
2.57	13.93	0.67	`index2adr`
2.19	14.50	0.57	`luaV_gettable`

Not bad at all. The function match() is the LPEG execution engine, which matches my intial thoughts on the code. It wasn't much work to remove extraneous SIP headers I don't bother with, and to simplify the method parsing (see above). Re-profile the code and:

Modified LPEG—Each sample counts as 0.01 seconds.
% time	cumulative seconds	self seconds	name
14.25	3.67	3.67	`luaV_execute`
11.22	6.56	2.89	`luaS_newlstr`
10.49	9.26	2.70	`match`
6.33	10.89	1.63	`luaD_precall`
5.20	12.23	1.34	`luaH_getstr`
2.76	12.94	0.71	`index2adr`
2.58	13.61	0.67	`luaD_poscall`
2.41	14.23	0.62	`luaV_gettable`

match() drops from first to third place, so that's good. And a load test done by the QA engineer showed an easy 25% increase is message processing.

But that's really as far as I can go with profiling. I did a run where I removed most of the validation checks (but only after I saw none of them were triggered over the past 30 days) and didn't see much of a speed improvement. So I really need to profile the Lua code as Lua code and not as C.

That's going to take some work.

Monday, August 19, 2019

Notes on an overhard phone conversation at The Ft. Lauderdale Office of The Corporation

“Hello?”

“Yes, who is this?”

“Who is this”

“This is … Sean.”

“And this is … XXXX [of the IT department].”

“Okay.”

“This is in reference to … ”

“Your email … ”

“About … ”

“Um … the laptop?”

“Oh yes! Sean! Of course! See, I get a lot of spam calls these days.”

“Yeah, I get a lot of phishing emails from you guys these days.”

“Ha!”

Wednesday, August 14, 2019

“Here's a nickel kid. Get yourself a real computer”

“Here you go, kid,” said Dad, as he handed me a book with a bright yellow jacket. “I heard this ‘Linux’ is the next up-and-coming thing in computers.”

I look at the title: Linux for Dummies: Quick Reference. “Um … thank you. You do realize I run Linux both at home, and at work, right?”

“Hey, maybe you can learn something from it.”

So I'm skimming through the book and … elm? pine? rsh? FVWM? When was this book written? … Oh … 2000. That explains it. Everybody these days are running mutt, ssh and GNOME.

It'll fit nicely on the shelf next to Sams Teach Yourself TCP/IP in 24 Hours and Inside OS/2.

Sunday, August 11, 2019

See, this is one reason why I'm leery about updates

A few days ago I noticed my iPhone notifying me of a “critical security update.” And it was only for the iPhone, not the iPad. Sigh. Fine. Download, install, and get on with my life.

Only a few days go by and I finally clued in that I wasn't receiving any actual phone calls! Not that that really bugs me, as most of the calls I get these days are spam calls from around the country, but it was odd that my dad has left two voice mails and yet, his calls did not show up on the recently called list.

So I check, and yes, I have no service. I try rebooting the phone, and that didn't work. I tried resetting the network, and that didn't work (and had the side effect of wiping out all known passwords for existing Wi-Fi networks).

Bunny suggested I go through the trouble shooting pages on the Monopolistic Phone Company website as she waited on the phone for a Monopolistic Phone Company Representative and the race was on to see who finished first.

Turns out, I won. I think it was step five where the Monopolistic Phone Company had me turn off the phone (and by “turn off the phone” I mean a hard power down and not just shutting off the screen), pull out the SIM card, push the SIM card back in, and turn the phone on. That turns out to have worked.

And now I can receive all those spam calls warning me that this is the final, no, we really mean it, final warning that my car warrantee has expired and if I don't act now I'm doomed to financial ruin. I honestly don't know how I lived without those calls.

Saturday, August 10, 2019

From chocolate ice rock to vanilla ice cream

My friend Squeaky replied to my chocolate ice rock post backing up Bunny's assertion that sugar content is key when making ice cream—to little and ice crystalization takes over making for a rather solid ice rock than ice cream. So on Friday, I went back to basics and made the basic vanilla ice cream receipe:

2c (500ml) heavy cream
1c (250ml) whole milk
¾c (180ml) sugar
2tsp (10ml) vanilla extract

Mix, chill, churn.

I wasn't quite satisfied with making a vanilla ice cream, so I decided to add cherries—I chopped up a bunch of cherries (the hardest part was getting the seeds out—man they were stubborn), a bit of sugar, chill, and add in the last few minutes of churning. I was initially concerned because the instant I added the cherries, the mixture starting loosening up—I think the cherries to a bit too warm. Next time I think I'll freeze the cherries before adding them.

But after sitting in the freezer overnight, the results were much better—I actually had ice cream and not a large rock. Lesson learned—sugar is key to ice cream.

Thursday, August 08, 2019

Who knew ice cream could be so hard?

We have an ice cream maker. I like chocolate ice cream, the darker, the better. And the instruction manual for the ice cream maker lists a recipe for a “decadent chocolate ice cream” which not only calls for Dutch processed cocoa, but 8 ounces (230g) of bittersweet chocolate. I opted for a really dark chocolate, like on the order of 90% cocoa dark chocolate.

Yeah, I like my chocolate dark.

I'm also trying to cut sugar out of my diet as much as possible, so I decided to use a bit less surgar than what the receipe calls for, so this stuff isn't going to be overly sweet.

I get the ice cream base churned, into a plastic bowl and in the freezer, and I wait for several hours, eagerly awaiting some deep, dark, decadent chocolate ice cream.

I end up with a deep, dark, decadent ice chocolate rock.

This isn't hard ice cream. This isn't even ice cream. It's an ice rock is what it is. I try dropping the bowl a few inches onto the kitchen counter to show Bunny how rock-like it is, and the bowl hits the counter, bounces off and shatters onto the floor.

I mentioned it was in a plastic bowl, right?

There are shards of plastic across the kitchen.

The deep, dark, chocolate ice rock is in one piece.

I think the ice cream base was too dense for much, if any, air to get whipped in while churning. Bunny thinks the low surgar content contributed to the rock-like consistency. Both are probably to blame for this. I do recall that the last time I made the “decadent chocolate ice cream, but with all the surgar,” it did tend towards the harder side of ice cream. So I think the next time I should try the basic vanilla recipe with less surgar and see what happens. If that turns out fine, then try the basic chocolate recipe.

The “Tonya Harding Solution” to computer benchmarks

… we knew we had to do more to truly earn those extra credit points. Luckily, I had one final optimization idea:

The Tonya Harding Solution: The benchmark program works by calling the optimized function, calling the naive function, and comparing the two times. And this gave me a truly devilish idea. I added some code to calc_depth_optimized that created a child process. That child process would wait for calc_depth_naive to start running, then send a SIGUSR1 signal to the benchmark process. That signal would interrupt calc_depth_naive and jump to a special signal handler function I'd installed:
void our_handler(int signal) {
    // if you can't win the race, shoot your opponent in the legs
    sleep(image_size * 4 / 10000);
}
So while we did implement a number of features that made our program faster, we achieved our final high score by making the naive version a whole lot slower. If only that 4 had been a 5 …
CS 61C Performance Competition

I'll have to hand it to Carter Sande for literally beating the competition in benchmarking.

(Although it wasn't Tonya Harding who did the attack, but Shane Stant, hired by Harding's ex-husband Jeff Gillooly who attacked Nancy Kerrigan with a police baton and not a gun. Harding herself claims she had nothing to do with the attack.)

Unfortunately, my blog on Gopher is a second class citizen

I will be the first to admit that my blog on gopher is a second-class citizen. When I wrote the gopher server I took the quickest and easiest way to adapt my blog to a (close enough) text-only medium by feeding requests through Lynx. Note I didn't say “well done” (of course not! I said it was a “medium!” Ba-dum-bump! I'll be here all week! Don't forget to tip the wait staff!) or even pretty.

For instance, this entry looks like this via gopher:

Extreme contradiction, Brevard edition

So Bunny and I came across this lovely bit of signage in downtown
[1]Brevard:

[“The white zone is for immediate loading and unloading of passengers only.
There is no stopping in the red zone.” / “The red zone is for immediate
loading and unloading of passengers only. There is no stopping in the white
zone.” / “No, the white zone is for loading of passengers and there is no
stopping in a RED zone.” / “The red zone has always been for loading and
unloading of passengers. There's never stopping in a white zone.” / “Don't
you tell me which zone is for loading, and which zone is for stopping!”]

So which is it? Loading, or parking? Or loading of wheelchairs for parking?
Or parking for wheelchairs to be loaded? I'm so confused!

References

1. https://www.cityofbrevard.com/

First off, there's no indication that there's a photo on that page, unless you realize I'm using a very old web convention of describing the image contents by placing said description inside of square brackets.

Secondly, there is no actual link to the picture on the converted entry.

Third, on most (all?) graphical browsers, just holding the mouse over the images will pop up the text above (I don't think many people know about this).

And fourth, the text is a reference to the movie “Airplane!” which does fit the subject of the picture on that page, which is of two traffic signs giving conflicting parking directions (this really doesn't have anything to do with the second-class status of the post on gopher—just more of an FYI type of thing).

I used Lynx because I didn't want to bother writing code to convert HTML to plain text—especially when I had access to a tool that can do it for me. It's just that it doesn't really do a great job because I expect the HTML to do the formatting for me. And I really do need to write a description of the photo in addition to the caption I include for each picture. Ideally, it would look something like:

Extreme contradiction, Brevard edition

So Bunny and I came across this lovely bit of signage in downtown
Brevard [1]:

[Image of two traffic signs one above the other. The upper one says
“NO PARKING, LOADING ZONE” and the lower one saying “RESERVED PARKING
for the HANDICAPPED”—“The white zone is for immediate loading and
unloading of passengers only. There is no stopping in the red zone.” /
“The red zone is for immediate loading and unloading of passengers only.
There is no stopping in the white zone.” / “No, the white zone is for
loading of passengers and there is no stopping in a RED zone.” / “The
red zone has always been for loading and unloading of passengers. There's
never stopping in a white zone.” / “Don't you tell me which zone is for
loading, and which zone is for stopping!”] [2]

So which is it? Loading, or parking? Or loading of wheelchairs for parking?
Or parking for wheelchairs to be loaded? I'm so confused!

References

[1] https://www.cityofbrevard.com/
[2] gopher://gopher.conman.org/IPhlog:2019/06/13/Confusion.jpg

And then reality sets in and I'm just not up to writing an HTML-to-text translator right now.

Sigh.

Sorry, gopherspace.

Tuesday, August 06, 2019

An MJ12Bot update

When last we left the MJ12Bot saga, it was pretty apparent it wasn't a well written bot, but true to their word, they haven't crawled my server since.

“The Knowledge AI” bot however … it is trying to repeatedly fetch /%22https:/mj12bot.com/%22 from my web server.

What is it with these horribly written web bots?

There are even bots crawling gopherspace

My webserver isn't the only program beset by bots—my gopher server is also being crawled. I identified one bot repeatedly trying to request the selector (the gopher equivalent of a web page) Phlog when it should be trying to request Phlog: (note the ending “:”). On the web server, I could inform the client of the proper link with a “permanent redirect” and hope it gets the hint, but gopher lacks such a facility. All this bot was getting back was the rather lack luster gopher error, which for an automated process, is pretty darned hard to distinguish from actual content, due to the simplicity of the protocol.

Oh a lark, I decided to see if there was a gopher server on the IP address of the bot, and lo', there was. I was able to send an email to the organization responsible, and they fixed the error.

That still left a few bots that thought I was running a web server on port 70. Yes, I was getting requests for “GET / HTTP/1.1” over and over again, and these particular bots weren't getting the clue they weren't talking to a web server by the lack of proper web server response. I decided to handle these by replying as a tea pot because why not? And to further support the joke, my gopher server will not only respond to the web method GET but also BREW (and to think I wanted to write a gopher server, not a web server … sigh). Hopefully that will placate them and they'll go away (although on second thought, I think I should have done a permament redirect to gopher://gopher.conman.org/ to see how well the web bots would handle that!).

The Boston Diaries

Tuesday, August 20, 2019