iappslx
3 Topicslog local0. is not a debugging strategy!
But let's be honest...with iRules, it's pretty much all we've had. If you have ever debugged an iRule, you know the ritual. Former F5er Jibin_Han in an article once called the log command is "the crudest of debug facilities." He was not wrong. It is the printf of application delivery, and at high traffic the logging pipeline will happily truncate your output just to keep things spicy. So back in TMOS 13.1, he shipped something much better: ltm rule-profiler. It is a passive tracer baked right into TMM. (Did you know this? Most don't, including most F5ers I talk to!) You do not touch your script. You tell it which virtual server, events, and occurrences to watch, you flip it on, and it emits a timestamped execution trace of everything your iRule did. Events firing, rules matching, the Tcl VM grinding through bytecode, native commands getting dispatched, variables changing. The whole shebang. There is just one catch. Ok actually two. It is tmsh-only. No GUI, no REST endpoint, no nothing. You configure it by hand and you start and stop it by hand. The not so fun part, the output looks like this: 1780079189187194,RP_EVENT_ENTRY,/Common/testvip-http,CLIENT_ACCEPTED,22623,0x70373707000576,10.1.10.6,36086,0,10.1.10.50,80,0 1780079189187210,RP_RULE_ENTRY,/Common/testvip-http,/Common/myrule,22623,0x70373707000576,... 1780079189187225,RP_RULE_VM_ENTRY,... 1780079189187240,RP_CMD_BYTECODE,/Common/testvip-http,push1,... Now multiply that by a few hundred lines, sprinkle in microsecond timestamps you are expected to subtract in your head, and remember that every single custom iRules command is actually a round trip out of the Tcl VM and back into TMM. A command, inside a VM, inside the microkernel. We need to go deeper. Reading it raw is less "performance analysis" and more "staring at the green rain in The Matrix and pretending you can see the woman in the red dress." The data is genuinely great. It's just wearing a CSV trench coat and refusing to make eye contact. But that ends now. Let's talk about Rültracer. What Rültracer is Rültracer is an iApps LX extension that gives ltm rule-profiler the face it always deserved. When Jibin_Han released his 3-part article series (linked at the bottom of this article) introducing the rule-profiler, we had a couple interns who built an analysis engine called Campfire that used a perl-based flamegraph package to display the trace in context of the "lift" of each occurence within a trace. The challenge was you had to manually configure everything on BIG-IP, send the logs somewhere, collect those logs, then import them into where you built campfire to run. A lot of manual work to get to the good. But Rültracer? It runs on the BIG-IP. An on-box Node worker handles the unglamorous parts: it configures the profiler, sets up (and tears down) the log publisher, captures the trace stream into a per-session file, and serves that file to a browser app. The browser does all the parsing and visualization client side, so the box just ships raw CSV and gets out of the way. What you get: A sequence diagram and step-through debugger. The trace becomes a UML-style sequence diagram across six lifelines (Users, Event, Rule, Rule VM, Command VM, Command), with the TMM and Tcl VM sides color coded so you can actually see every handoff between the microkernel and the interpreter. Which matters, because that back-and-forth is exactly where iRule inefficiency likes to hide. Next to it sits a linked step-through with a timeline scrubber, variable state, and command replay. Click the diagram, the table follows. Click the table, the diagram follows. There's a Tclsh disassembler you can enable as well, and as long as you're willing to modify the parts of the iRules code under test. I wrote an article years ago on this disassembly functionality, it's worth the read to see what this functionality affords you. iRule source mapping. It pulls your actual iRule source and lights it up: which commands fired (with microseconds and counts), which branches never ran, and which lines were ambiguous multi-matches. Your code, annotated by what the trace really did. (this part is early stages, it needs work.) Flamegraphs, with diff. An interactive flamegraph where width equals inclusive time, so the widest frame is your prime suspect. Find the slow command without playing Where's Waldo. Captured a "before" and an "after"? The diff view paints frames red and blue by how their self-time shifted, so you can prove your optimization actually optimized. Cycles versus CPU. Rültracer takes the box's own ltm rule stats hardware cycle counters and turns them into honest performance tables: cycles to microseconds, percent of a CPU per request, and max requests per second before your iRule becomes the bottleneck. It even reconciles the authoritative cycle counts against the trace-derived numbers, and the gap between them is the profiler's own overhead. These are numbers you can bring to a capacity-planning meeting without getting laughed out of the room. This is based on Deb Allen's yesteryear work in excel for computing capacity with iRules and my update in doing this with python much later. Reports and exports. Export a capture as self-contained HTML, JSON, a Mermaid sequence diagram, or Brendan Gregg folded stacks. Share it, attach it to a ticket, or feed it to your own tooling. Multi-TMM aware. Captures that span multiple TMMs get partitioned by context id with a scope selector, because of course your traffic did not politely land on a single TMM. No (post RPM install) build steps, no cloud, no telemetry, no agent. Vanilla JS in the browser, a small ES5 worker on the box, fully self-contained. And it is a lab tool on purpose: tracing adds significant TMM overhead, so this is not something you run in production. Rültracer tears the profiler and publisher down for you on teardown, so you never accidentally leave the tap open. Installing it Rültracer installs over SSH. You build the RPM on your workstation, copy it to the BIG-IP, and run the installer on the box as root. The installer provisions the persistent data directory, installs the package through the iApps LX framework, runs the post-install step, and confirms the workers came up. Replace and with your BIG-IP's SSH host and port. If it answers on plain old port 22, drop the -P / -p flags. First time on a fresh box The installer script lives outside the RPM, so it rides along once: Copy the installer on the box (one time only) scp -O -P <port> build/install-onbox.sh root@<host>:/shared/images/ Build, ship, and install ./build/build-rpm.sh 0.7.1 0001 scp -O -P <port> build/dist/rultracer-0.7.1-0001.noarch.rpm root@<host>:/shared/images/ ssh -p <port> root@<host> /shared/images/install-onbox.sh 0.7.1-0001 Because the installer runs as root, it creates the session data directory owned by the restnoded worker user before the workers start (the worker is uid 198 and cannot create directories under /shared/ on its own). When it finishes, it prints your UI URL: https://BIG-IP-host/mgmt/shared/rultracer/ui/ Open that, and you are in. Follow-on updates The installer is already on the box, so the next rounds are just bump, build, ship, install like above. That is an in-place upgrade and it keeps your saved sessions. If you ever want a clean slate, pass --reinstall, but note it wipes session data, so hit the Sessions tab's "Download backup" button first if you care about what is in there. See it in action (The walkthrough covers a live capture end to end: pointing the profiler at a virtual server, driving a little traffic, then digging through the sequence diagram, flamegraph, and cycle stats on a real trace.) Conclusion This was a fun project to bring together something I've played with a lot since the v13.1 release but could never quite figure out a packaging solution to make it functional enough to rely on. You can find the code in the Rültracer repo on Github. Let me know in the comments if you take a look at this and submit any bugs ore feature requests as an issue out on Github.
240Views2likes0Comments