Monday, July 24, 2017

Sony Experia XZs in the US with fingerprint reader

Got a Sony Xperia XZs about a couple of months ago to replace my iPhone.
Main reason was with our move to Montevideo I wanted a dual SIM phone and I didn't want a Samsung.

The Samsung deal is a long story, but in short, Samsung tech support in the US was the only people ever that mistreated when trying to get camcorder repaired, after literally stealing a device we shipped to their repair facility and claiming they shipped it back to us and we were trying to rip them off. Anyway, we just don't buy anything Samsung at our household, period.

I digressed, going back to the Xperia. Great phone! But I badly missed the fingerprint reader, until I found out that in the US they are simply disabled by firmware.

After I learned that, the thought about figuring out how to change the firmware stuck with me. I decided to try the procedure when my son eventually discovered my unlock key simply by watching me do to unlocking pattern a couple of times.

I will not reproduce here the whole process, you can do Google search and you will find plenty of pages that explain it.

In summary this is what I did:

Downloaded xperifirm tool. With that tool I found the right Indian firmware for my phone and downloaded it.

Got the flashtool for Sony devices. Built a firmware file from the downloaded and unpacked files.

A note here is to delete a fwinfo.xml file on the root download folder. According to one page I found if that file is included in the firmware file it gets corrupted.

With the firmware file built I went into "flashing mode". When you initiate the flashing process you are prompted with a dialog to exclude certain items and wipe others. I simply used the default settings and that works well to replace the firmware without loosing any data or config.

A note on the flashing process. Relatively early in the process, the console showing the files being upload to the phone suddenly stopped showing any activity. After a couple of minutes of inactivity I thought I finally bricked the phone, but armed myself with patience and waited. Eventually the flashtool picked up and kept going reporting on files being uploaded to the phone until it was done.

I unplugged the phone and turn it back on. Got another scare when the Xperia logo color animation took forever... Again I thought maybe I bricked the thing and all I got was a fancy screen showing an animation. But no, eventually the phone booted, reported an upgrade in process and was usable right from the start.

I went to the security settings and to my surprise I found the fingerprint manager, fully functional!

For this phone this feature is a game changer. If you own one of this great phones, you have to do this flashing and get the fingerprint reader working. You won't regret.

Friday, January 13, 2017

Yet another way to look at technical debt to help with prioritization efforts

There have been many authors proposing different approaches to categorize Technical Debt.
You have Martin Fowler with his TechnicalDebtQuadrant.
Then you have Uncle Bob making a strong distinction between Technical Debt and "a mess", which I happen to disagree with, a mess is also debt.
Then if you read Uncle Bob's article, I like the comment by Mark H where he suggests perfectly good code can "bankrupt" and become debt. I definitively love that concept.


At the end of the day, let's go back to the root of the word debt.
Using the same theme of dissecting a word definition I used on other articles, let's start by using a definition of the word debt straight from Google:

debt

something, typically money, that is owed or due.

So, in short, a debt is something we owe. Legacy code, messy, can be become a debt? O yeah... it can. Is it always "debt"? Absolutely not!

Go back again to Mark H comment on Uncle Bob's post. The key thing to take into account is when legacy code becomes bankrupt. What's the event that triggers its bankruptcy?

So, putting that digression aside, let's risk a definition for Technical Debt:

Technical Debt appears when we ought to do something about a piece of code in order to keep it viable.

Let's look a the three pieces I underlined:

  1. Technical Debt appears: The point of this is that not always we do "create" tech debt from the start, nor in a deliberate or inadvertently way (in contrast to Martin's quadrant). Perfectly fine code, as written some time ago, can become a debt after passing thorough a "legacy" stage. When this happens? when we...
  2. ought to do something (about the code): If we have code that is perfectly fine as-is. We are good, there's no debt. If we have a piece of code that it's a mess, and it was born as a mess, we got ourselves into credit card debt, unsecured debt (there's not even an asset to back it up). If debt was incurred in a deliberate fashion to accelerate a deliverable, maybe we are talking of a home mortgage or a line of credit. Or, for existing code that became a liability at some point, maybe we are talking a depreciating asset that it's costing us more to maintain that the intrinsic value it provides. Either way, as soon as we have a piece of code that we are forced to plan to take action upon it in order to...
  3. keep it viable: we are talking about technical debt. It may happen we have pieces of code that are not "ideal", perfect, algorithms that are not necessarily the best performing for a problem but they are definitively "good enough" in our market or as required by our clients. Are those debt? I would argue they are not debt. A piece of code becomes debt when its viability is in question. A perfectly nicely written piece of code can become debt if suddenly a change in its running platform makes it obsolete or unsupported. The code is great, nicely written, but its viability is in question.
Now that we cleared what is debt (to a degree) from what is NOT debt, let me propose a simple two-way to look at technical debt that should help prioritize paying down.

As with any debt, I like to think it in terms of two types:

  1. Neutral
  2. Debilitating

Neutral Debt

Why the word "Neutral"? Well, I wanted to use a word that doesn't denote good or bad. Something in the middle. This is in purpose, because personally I believe having no debt will be the ideal we should strive for, yet sometimes we will have to incur on it but definitively I don't want to portray that as a net positive. Therefore the choice of "Neutral" as a word to define it.

What is Neutral Debt?

Neutral Technical Debt is debt that doesn't endanger the product operation nor poses increasing monetary costs to keep the code viable on the short to mid-term.

In another words, we know we have to do something about it, we know it will break down at some point, but at this point in time and for the mid-term (pick your length of time that best fits you) the code will work and it won't be a resource drain to maintain. The code is still an asset, it's doing it's job, yet we know we will have to do something about it "at some point".


Debilitating Debt

Easy. Pretty much negate Neutral Debt and you got Debilitating Debt.
You got a piece of code you find yourself investing time again and again to keep it working. You fix a place, and break five places inadvertently. Each new feature you add the code smells multiple like well fed rabbits. Your backlog is filled with "refactorings" in order to add new features. And all of this is happening right now, and getting worst everyday to the point you can't even think about the long term.

Well, I could keep going on the narrative above. You get the point. Look at the word I used: "Debilitating". With this type of debt, you become weaker every day, you can do less of what really matters because you find yourself on this never ending cycle of fire fighting broken and unwieldy code.

Prioritization

So, when need to do your next technical debt prioritization meeting, try separating it first into Neutral vs. Debilitating debt and only focus on discussing Debilitating Technical Debt to further decide what to do.
Upon the right time there will be pieces of Neutral Technical Debt that get "demoted" (or if you prefer "promoted") to Debilitating Technical Debt. Maybe that's how you start the meeting, quickly go thorough existing Neutral Technical Debt and assess if any entry should be changed to Debilitating.

If you want to get fancy, you can rank them from #1 to #5, with priority #1 being the worst ones, those that get your company hooked in those strong painkillers (being your team the painkillers).

Hope this helps your tackle your technical debt problem.

Saturday, November 12, 2016

How to integrate native code in your Java and C# applications and don't die in the attempt

You read the title. Integrating native code in your C# and Java apps seems easy, very easy at first right? In C# you just declare your externals, hold on to IntPtr pointers, pass them to your native code when you want something done and that's it.

In Java, you create a Java module with all of your externals, compile the module, use javah to produce a C header file, and then fill in your .c JNI file.

Well, the easiness ends there.

There are four major issues that need to be addressed, in both languages, if you fail to do so very likely your native code integration with C# and Java will be unwieldy to use, buggy (crashy!)( or both.

The four key considerations to be discussed:
  1. How to move data in/out the native library. There are tons of articles covering this topic for C# and Java, and in general terms it ends up being a matter of personal choice the final approach used, so I will not touch this topic on this post.
  2. Lifecycle of unmanaged native objects.
  3. Lifecycle of managed wrapper objects.
  4. Native objects dependencies.

Lifecycle of unmanaged native objects

How to manage the lifecycle of native objects? That's a question you face as soon as you start planning how to integrate native unmanaged code in your nice managed language. 

Why is this an issue?

Well, assuming you wrote your unmanaged library in a language with explicit memory management of some kind, now you have to bridge the gap to languages that are garbage collected, and I tell you right now: not C# nor Java GC play nice with unmanaged memory if you are not careful, and .NET is worse in fact, because how nice its GC works...

Getting back to our topic at hand. What are the typical strategies to manage the lifecycle of unmanaged objects from the perspective of our managed wrappers?

There are two common strategies:
  1. Make your wrapper objects implement IDisposable in C# or Closeable and/or AutoCloseable in Java.
  2. User finalizers to destroy your managed objects.
Both approaches work, and you may end up using one or the other depending on the nature of the underlying unmanaged object.
If your unmanaged object is "pure memory", I suggest you use a finalizer to get rid of the unmanaged object. Why? Because the resulting wrapper code will feel more "natural" to your users. I'm sorry if you read all over the place not to use finalizers, they are available for a reason, just don't abuse them.

IDisposable or Closeable force the developer to "do something else" besides creating an object.
Let's remember in the world of GC languages developers don't want to think when they need to release resources or memory. The less we force them to think about this, the better.

If your unmanaged object holds some resource, such as a file handle, socket, database connection, etc. I strongly recommend using IDisposable, Closeable or AutoCloseable. Nowadays developers know they should look if the objects they are creating implement these type of interfaces, and they know how to deal with them:

Use "using" clause in C# or manually call Dispose() method at the end of life of the object. 
In Java close the close() method or wrap it's using in try ( ) { } block.

All good here, and things seem simple, right?

Not so quick.

Lifecycle of managed object wrappers

We have our unmanaged objects wrapped into managed objects.
We decided to user IDisposable or Closeable pattern on some cases, and in others we decided to get rid of our unmanaged object using finalizers (sinful developers!).
All good here. Now, here is exactly where the fun begins, because .NET and Java GC implementations make no guarantees on the lifecycle of the wrapper object when you make calls to unmanaged code. Java is an exception if you pass to the JNI function the reference to the object itself, but that's not usually done. The most common implementations pass a "handle" (IntPtr or long) to the unmanaged code. 

That's exactly where the problems begin. It's not uncommon at all, trust me on this, that the wrapper object becomes unreachable when calling the unmanaged code and the program makes the object that is just calling unmanaged code eligible for garbage collection. The outcome of this is typically not pretty: segfaults, access violations and crashes. Typically very hard to debug.
Imagine, you are making an unmanaged call, and *while* the unmanaged code is running the wrapper is destroyed. In the case your wrapper properly cleans up when the finalizer is called by the GC, you are out of luck, the underlying unmanaged memory will be freed and the object destroyed while you are doing something with that memory on a different thread. Ouch!

In the case of classes that implement IDisposable, Closeable or AutoCloseable interfaces there's no problem as long as the proper pattern to ensure the disposal procedure is called, because the wrapper object lifecycle ends when calling Dispose() or close() methods, so you are guaranteed to have a live object on all unmanaged code calls.

The problem with these patterns though is that developers oftentimes overlook the fact a class they are using implements any of these interfaces and let the GC handle finalization of the object, which could lead to the object being destroyed early.

Visual Studio compiler will not warn the developer that IDisposable pattern is not used properly unless Code Analysis is enabled on the solution, and Java compiler will not warn the developer either if close() or try() { } pattern not used. I tried running code analysis with JetBrain's IDEA and could not found an inspection for this situation either.

Now, the pervasiveness of this "early destruction" issue depends on many factors. In the case of .NET, I have not found that applications running in Debug mode show symptoms of objects destroyed while unmanaged calls are under way, but in contrast, it's well documented that when the application is compiled in Release mode this behavior is common. GC tries to be more effective and efficient in Release mode? I don't know the reason, but I can confirm it happens and it's very prevalent.

If you are curious, check out this tests here: https://github.com/jsbattig/csharp-gc-helper/blob/master/gc-helper-tests/tests/UnmanagedObjectLifecycleTests.cs#L91-L171 to verify this issue.

Java is supposed to be prone to the same problem, but I have not attempted to verify the behavior yet.

Solving the issue of early disposal of managed wrappers

How to solve this issue?

.NET 

.NET provides a clear path to solve this issue. It requires the developer writing the wrapper to be disciplined stating every time unmanaged calls are made that may rely on ensuring a wrapper object is alive when the life of the wrapper object *may* terminate (it may terminate actually even later). 
How do you do this? By using GC.KeepAlive(object) method.

At first sight, GC.KeepAlive() is counterintuitive. When calling this method .NET is not somehow keeping the method alive *when* the method is called, which is the first thing you may thing the method does by its name. .NET will keep the object *reachable* and therefore alive until the point where the method is called.

So, what a developer must do is make sure there's a call to GC.KeepAlive(TheObject) *after* the call to the unmanaged function making sure this call to GC.KeepAlive() is reachable from the perspective of the compiler.
When the compiler sees this KeepAlive() call, it will not mark the object as unreachable thus garbage collectible.

Java

In Java the story is a bit different. Java doesn't have such as thing as GC.KeepAlive(), but Java compiler will guarantee that an object is alive if it was passed as a parameter to a JNI function. As long as we pass entire objects to our JNI functions, in Java we are good.
The problem is that oftentimes JNI libraries are not written like that. It's easier to pass primitive types representing our handles to the JNI code. A typical datatype used to hold these "handles" is the long datatype, which can fit a 64 or 32 bits pointer. In Java, if you pass this handle to the JNI function by accessing a long field, then you lose the guarantee of the object not being collected while the JNI code is running.

This is the scenario where Java GC behaves exactly like .NET GC (but I have to recognize by my experiments that Java GC is not nearly as aggressive as .NET GC). The problem with Java is that it doesn't provide a GC.KeepAlive() equivalent to ensure the lifecycle of our object while the JNI call is being executed. 
There are many strategies you can try by "doing something" that keeps the object referenced. In most cases, these strategies may not work at all because of two things:

  1. Compiler optimization (the compiler may completely remove the code if found inconsequential).
  2. Instruction reordering (the code you wrote to keep your object referenced was moved on top of the JNI call).
So, how do you solve this problem in Java?

Well, if you want to learn more about the details, and different strategies, read this excellent article by Jason Greene. This is from where I extracted the following piece of code that implements a .NET equivalent of KeepAlive() that you can place in a base class for all of your wrappers:



If you want the full explanation why that code works, and why it's more desirable than a plain write to a volatile field in your class, read the article linked above.

So, we solved the problem of early disposal in .NET and Java, that's it?

No, that's not it.

Native objects dependencies

The final problem I wanted to discuss, is how to handle native objects dependencies. 
If you created a wrapper for a library for a model that has even just simple hierarchical structure between classes, you will face the problem of how to handle dependencies (parent-child relationships) lifecycles. 
What I mean by this?

Well, let's start with the basic premise that on garbage collected languages such as Java and .NET, the order in which finalizers are called is completely unpredictable. What's the consequence of this?

If you have an object A, that has as a parent object B. And let's say that object A destruction code requires that object B is alive in order to perform some cleanup. If you decided not to use IDisposable, Closable or AutoClosable or if you simply forgot to use the proper primitives to ensure calls to Dispose() or close(), then you are out of luck.

When both A and B become unreachable, there's no guarantees on the order of the finalizers calls.

Think about C# pattern to write Dispose() method. If the Dispose() method was not explicitly called, meaning it was called by the finalizer method, you should not touch any managed object you own. Why? Because they may or may not have been finalized before the class in question has been finalized. That simple. Even though this class has references to other managed objects, the class can't assume those objects are still alive... 

What I ended up doing to handle unmanaged object parent/child dependencies is to write a small library in C# and ported it to Java that works as a GC helper. This library allows to register unmanaged object handles, destruction delegates and parents.

The key points I decide to hit with this library are:


  1. The library is thread safe for registration, unregistrations, adding and removing dependencies.
  2. Objects are reference counted.
  3. Multiple registrations of the same object are permitted. This happens on situations where the same underlying object is returned by an unmanaged function call while multiple wrappers may be created.
  4. An object can have multiple parents (dependencies). When registering a parent, its reference count is atomically increased by 1 and when an object is destroyed, all its parents have their reference count decreased by 1 immediately after the object destructor delegate has been called.
  5. Destructor delegates are called from a separate "agent" thread to avoid the potential performance impact on the GC collector thread and to reduce the risk of crashing the GC thread itself if something goes wrong when calling these delegates.
  6. The library is entirely written in a lock-free approach.
  7. To further remove contention, an entry in the core collection is represented by a Pair<ClassType, HandleType>. This helps on situations where the same handle value is provided for objects of different class, which is possible when the wrapper doesn't manage the lifecycle of the underlying object but rather only carries a handle to it, the object can be destroyed at some point, the wrapper is on queue to be removed yet a new handle to another object of a different class is provided.
These are the two repos that implement this library:

https://github.com/jsbattig/java-gc-helper
https://github.com/jsbattig/csharp-gc-helper

Summary

If you are going to wrap an unmanaged/native library in C# or Java, hit the following points, and you can't go wrong:
  1. Decide which classes will be implemented as:
    1. Plain and simple managed objects that rely on regular GC plus a finalizer to trigger underlying object destruction.
    2. IDisposable, Closeable or AutoCloseable objects that rely on the developer to implement the proper disposal pattern.
  2. Use GC.KeepAlive() or an analogous in the case of Java in order to ensure your wrapper objects (and the underlying native object) are not destroyed while making an unmanaged call.
  3. Decided on a strategy to manage unmanaged object dependencies (parent/child relationships). Remember that you can't rely on GC finalizer call order.

Best.

Friday, September 2, 2016

Troubleshoot access violations using specific ImageBase address on libraries


Nothing more frustrating than an Access Violation error on a program compiled without managed code.
If you have worked with Delphi or C++ you know what I mean. 
To make things even worse, you may have to refrain from using unhandled exception managers for different reasons, most often than not security. This is a common situation for installed software.
Many organizations see stack dumps as security holes in applications that can be used to facilitate cracking of the software.

How can you make troubleshooting easier if you don't have an exception manager capturing the full call stack?

A common technique used implies compiling your app with source code matching production, and then using your debugger tool to navigate to an specific address in memory. Different debuggers will offer different ways to do this.

In the case of Delphi there's at least a couple of ways:
  1. Use the main menu Search|Go to address... option
  2. Or, use the CPU/Assembly view, right click anywhere on the assembly view and select Go to address... context menu
Either way, this works... sometimes...

The problem is that any time you create a new project with an IDE, there's a project setting that goes often overlooked that is created always with the same value. The default value.
This setting is the "Image Base" of the binary you will be producing.

What is the Image Base?


In short, it's the address where a module will *tried* to be loaded. See the following articles for details:


The issue here is that if this setting is left unchanged, the OS will "relocate" your binary when it's loaded as the default address will likely be used by another module. 
Of course when this happens, the likelihood that the binary is loaded at an address that matches the one in your machine where you intend to run the debugger is slim. You will do a Go to Address... punch in the address you got from your error message and most likely you will end up in lalaland.

To clarify, the address I mean you need to use to try to trace the location on the error is the highlighted in yellow below:



Now, if you set the ImageBase of your binary to something unique and acceptable (the value must be multiple of 64K), using Go to address... you will get to the exact place in the code (asm or source) where the error happened as long as the module was loaded in the same location while debugging.


Click OK, and you end up here:



As you can see, the memory address of the particular assembly instruction is highlighted, and it happens to be a few asm instructions below the line of code that generated the Access Violation:

s := PString(nil)^;


Where to do you change this ImageBase in your IDE?


Delphi:




In Visual Studio:



Hope this helps you with your Access Violation adventures.

Enjoy

Thursday, September 1, 2016

Running dynamically generated code in C# (Part 2)


In Part 1 of this topic I shared a GitHub repo that compiles code snippets in real-time, loads them as an assembly for execution.
A problem with this approach, widely discussed online, is that the assembly containing the code will be loaded in the currently running AppDomain making the newly loaded assembly impossible to unload.
In many cases this is not a problem, particularly on cases where the number of different instances generated code if finite and manageable. You can simply cache this "scripts" in memory and reuse them later when needed.

What about the cases where we don't want to clutter the memory and our main AppDomain with an ever growing list of dynamically generated assemblies?

Well, for those cases, luckily there's a way to unload the dynamic code, but it comes at a heavy cost.
Let's review what needs to happen to achieve this;

  1. The dynamically generated assembly must be loaded in a separate AppDomain instance
  2. The calls from the main AppDomain to the AppDomain hosting the dynamic assembly must be marshaled using MarshalByRefObject. This mean we will incur in about 20x performance degradation on the call itself vs. calling a method directly.
  3. To avoid serializing objects for sharing with the "script", a hack can be used casting an object's memory address to an IntPtr and back within the dynamic assembly. In order to do this, the following has to be done:
    1. Shared objects between main AppDomain and the AppDomain hosting the dynamic assembly must be compiled into a strong named assembly (signed) and installed into .NET GAC using gacutil tool.
    2. The host application must run with the attribute instructing to use LoaderOptimization set to MultiDomainHost
    3. The dynamically generated assembly should be loaded with MultiDomainHost option.
    4. If running the app on the IDE for debugging purposes, the option to let Visual Studio host the application must be disabled 

Without further due, the latest version of the repo has the code updated to enable running the "scripts" using a separate AppDomain and show how these dynamic assemblies can be unloaded.

That's it for now.

Friday, August 26, 2016

Running dynamically generated code in C# (Part 1)

The power of C# dynamic code compilation

Need to run dynamically generated code in C# with maximum performance?
Don't want to incorporate a third party scripting language?
Want it to be oriented to "simple expressions" or "code snippets"?

Then don't look further than C# itself. You have everything you need without having to incorporate third party code to your application.

The solution I'm going to propose works well if the dynamic code that will be run doesn't change often. This should NOT to be used a general purpose scripting language where users can throw any piece of code to run at any point. If that's the case, there's a couple of concerns that I will discuss later that need to be taken into account.

First, this post will revolve around leveraging class CSharpCodeProvider which allows the developer to compile an arbitrary piece of code within an application.
In order to use CSharpCodeProvider you will also need instances of CompilerParameters and CompilerResults classes.

The idea is to generate a snippets of code that can be called from the host program and return a result of an arbitrary expression, or even return no result at all.

When do you typically want to use this kind of functionality?

I would definitively leverage the power of these C# capabilities on the following cases:
  • File generation where some custom logic needs to be inserted on a "template" file.
  • ETL processing via a generalized engine with capability of using custom filters.
  • Custom data validations where the logic is not hard-coded by fetched from an external source (database, files, etc.)
Without further due, this is an open source repo that contains a full C# expression execution engine:


Now, if you reviewed the code in the repo, here are the two concerns you need to be aware of:
  • The only granularity you have from a security point of view with this approach is dictated by the Assemblies and Namespaces you make available to the code snippets and the Namespace itself of the objects made available externally. 
  • The code generated is generated as an in-ram assembly that gets loaded within the AppDomain of the running application and CAN'T be unloaded. You can imagine if you have a lot of highly changing dynamic code, you will be leaving all of this clutter behind for the life of your application.

Enjoy!

Wednesday, December 16, 2015

What's good logging on microservice-oriented components

Motivation

I've noticed very different approaches to logging on all of the micro-services we currently have at Sovos (which are a lot a this point).

Prior to our move to micro-services model based on our service-bus, we did have a big portion of Sovos's architecture designed around the concept of coarser services. Nevertheless, we did have pretty good and comprehensive logging model, and most services did log enough to be able to perform efficient and successful troubleshooting without requiring to reproduce problems in Development nor use a debugger.

I get the perception now that with our move to micro-services we are losing the grip on disciplined logging instrumentation on the services.

Let's start with a statement I want to be true for all micro-services we produce (this is a desire of future state essentially):

If it takes more than 5 minutes of troubleshooting to have a rough idea where a problem might be on a faulty service. The service lacks proper logging.

That's what we have to shoot for.

Since we moved to the micro-services model I've observed countless troubleshooting sessions that go for hours, until someone finally has to put the service in a debugger just to figure out it had a bad initialization parameter or something as simple as that...
It doesn't have to be like that.

Logging best practice #1


Every service should follow the best practice of logging at startup ALL initialization parameters (or critical commands) and shutdown. Use LogLevel=0 for this (meaning "always log").

This the example from our rxfile service initialization and initialization parameters logs:

11/12/2015 1:53:53 PM: Status:INFO -- Details=----------------------------------------------------------
11/12/2015 1:53:53 PM: Status:INFO -- Details=--        Remote Execution Module - File Manager        --
11/12/2015 1:53:53 PM: Status:INFO -- Details=CS: J3Y3MAJWPYBGJ250JDOEVQOEUP3LGXOSVSLADYCX55QRIILPDJPYLXVEVBDM10FHK24JNWNIR5TPKP
11/12/2015 1:53:53 PM: Status:INFO -- Details=Target Path: X:-Cerem-InBox
11/12/2015 1:53:53 PM: Status:INFO -- Details=Log Level: 5
11/12/2015 1:53:53 PM: Status:INFO -- Details=Restart Time: 06:00
11/12/2015 1:53:53 PM: Status:INFO -- Details=Timeout interval: 1000
11/12/2015 1:53:53 PM: Status:INFO -- Details=----------------------------------------------------------

As you can see, those are "INFO" log entries with the critical parameters for this particular application.

Shutdown log example:

11/12/2015 1:53:51 PM: Status:INFO -- Details=Stopping service
11/12/2015 1:53:51 PM: Status:INFO -- Details=Main timer disabled
11/12/2015 1:53:51 PM: Status:INFO -- Details=Waiting for execution queues
11/12/2015 1:53:51 PM: Status:INFO -- Details=Waiting for execution queues completed
11/12/2015 1:53:51 PM: Status:INFO -- Details=----------------------------------------------------------
11/12/2015 1:53:51 PM: Status:INFO -- Details=ServiceStop event complete
11/12/2015 1:53:53 PM: Status:INFO -- Details=----------------------------------------------------------

Notice the highlighted significant events logged upon shutdown. There's a reason for that. They allow to troubleshoot common issues every time a program has to deal with asynchronous queues or threads shutdown (who didn't have a deadlock when trying to shutdown a threaded process?).
With that informational logging on top of the shutdown logging you can trace how every piece of the application gets shutdown.
In the case of our micro-services, when running in console mode, we can capture Ctrl-C key combination with a simple Windows hook and initiate a clean shutdown.



The other thing I see often, is exceptions occurring on services that are simply absorbed by the code with no logging whatsoever. I've done this myself in a couple of places, but typically I will put at least a "// ToDo: needs logging" or something along that nature.
We need to be vigilant to code that could absorb exceptions to make sure there's proper logging in place.
A final though on that, hybrid micro-services will have exceptions serialized back to the caller. That's OK, as long as the caller logs the exception if it can't properly handled it.

Logging best practice #2


Ensure that ALL unhandled exceptions are logged as errors. Use LogLevel=2 for this unless the situation is Fatal, use LogLevel=1 for fatal errors.

Example from rxfile service:

11/12/2015 1:53:55 PM: Status:ERROR -- Details=Exception received from the Agent -ORA-00942: table or view does not exist
- processing environment -QAINEWPKD--
11/12/2015 1:53:55 PM: Status:ERROR -- Details=Exception received from the Agent -ORA-00942: table or view does not exist
- processing environment -TWED--
11/12/2015 1:53:55 PM: Status:ERROR -- Details=Exception received from the Agent -ORA-00942: table or view does not exist
- processing environment -DEVORAD--
11/12/2015 1:53:55 PM: Status:ERROR -- Details=Exception received from the Agent -ORA-00942: table or view does not exist
- processing environment -DEVNEWKEYD--
11/12/2015 1:53:55 PM: Status:ERROR -- Details=Exception received from the Agent -ORA-00942: table or view does not exist
- processing environment -NCOLLIND--

Those are logging entries caused by external missing tables on that target schema. The service can take the pounding of those exceptions and keep going fine, but it will log the problem nevertheless, hopefully some day maybe someone will read the log and figure out that either has to remove the entries so rxfile doesn't process those domains, fix the configuration or add the missing tables.



The other situation I see happening is exceptional situations that "somehow" are supposed to be handled within the code, therefore "hidden" from developer view when the software is running, but in the long run end up derailing the program with a crash or errors that become hard to track, unless you can log the trace of this unfortunate (handled) events.

Logging best practice #3


Log handled exceptions that could be "of interest" in the future to troubleshoot issues. Use LogLevel=3 or 4 for this depending on how bad the handled exception.

An example of this is a piece of code, again in rxfile service, where a file being accessed is locked for exclusive access by another process, therefore the service will retry a few times. Again, this is part of the process, so this log entry I think we do it only with loglevel=4:

11/12/2015 1:59:20 PM: Status:INFO -- Details=File found: X:-Cerem-InBox-JSBATTIGD-QFTAPDEPLOY-DMP@TPRDVYZ5BFJUT15HT5ZNYAZDY53IKDT43J2SFVBSIFSOCQBRWJGYNM55MP2FWT2Q2AHRVGQEMUPQFI0ESFDQQLLPDMFT45CXH4GPFZP-0000000000000000-post
11/12/2015 1:59:20 PM: Status:INFO -- Details=Failed to open file -retry no- 1-

That simple log entry can help you troubleshoot potentially issues with algorithms that rely on capturing certain exceptions to perform retries (or not).




Next one up my list is what I will call "major functions". Many times micro-service applications run big processes "in-line" as a direct response to a request, or on a separate thread asynchronously (some kind of garbage collection or resource cleanup of any sort).
When possible, it is good to log those as is not uncommon for this "large processes" to destabilize an application and make it crash. Many times you don't have a trace of the crash itself, but you know what happened immediately before that...

Logging best practice #4


Log "big or special operations" of any kind. Use LogLevel=4 for this.

Example of this "big" operations is a file cleanup operation that the rxfile service performs:

11/12/2015 1:53:53 PM: Status:INFO -- Details=----------------------------------------------------------
11/12/2015 1:53:54 PM: Status:INFO -- Details=Remote File Cleaning Agent running---
11/12/2015 1:53:55 PM: Status:ERROR -- Details=Exception received from the Agent -ORA-00942: table or view does not exist
- processing environment -QAINEWPKD--
11/12/2015 1:53:55 PM: Status:ERROR -- Details=Exception received from the Agent -ORA-00942: table or view does not exist
- processing environment -TWED--

Notice the interesting fact that there's errors coming after the highlighted entry. By merit of having that entry logged there, it's not hard to assess that those errors were in fact triggered as part of the execution of the file cleaning agent.



Bear with me. I have one more.

Next one up is logging to assist complex troubleshooting efforts. This is about logging pretty much everything with enough granularity to add value when troubleshooting. It's very important to think about the granularity piece, definitively you don't want to be hitting the log function inside a loop that iterates 100000 times adding numbers because you will spend more time evaluating if log or not to log with the configured loglevel than doing work.

Logging best practice #5


Log all "big or special operations". Use LogLevel=5 for this.

You want to have a "verbose" mode of operation to troubleshoot the most intricate aspects of the application. Think of this logging level as the closest thing you will have to Debugging in your IDE. Remember, you don't have access to use your IDE debugger in Production, so you better instrument your application to be an effective troubleshooter when the issues arise (they will arise...).

Here's an example of how rxfile service logs every one of the two actions it performs on files: open and process them, then delete them:

11/12/2015 1:59:27 PM: Status:INFO -- Details=File found: X:-Cerem-InBox-JSBATTIGD-QFTAPDEPLOY-DMP@TPRDVYZ5BFJUT15HT5ZNYAZDY53IKDT43J2SFVBSIFSOCQBRWJGYNM55MP2FWT2Q2AHRVGQEMUPQFI0ESFDQQLLPDMFT45CXH4GPFZP-0000000000000014-post
11/12/2015 1:59:27 PM: Status:INFO -- Details=File deleted: X:-Cerem-InBox-JSBATTIGD-QFTAPDEPLOY-DMP@TPRDVYZ5BFJUT15HT5ZNYAZDY53IKDT43J2SFVBSIFSOCQBRWJGYNM55MP2FWT2Q2AHRVGQEMUPQFI0ESFDQQLLPDMFT45CXH4GPFZP-0000000000000011-post
11/12/2015 1:59:27 PM: Status:INFO -- Details=File deleted: X:-Cerem-InBox-JSBATTIGD-QFTAPDEPLOY-DMP@TPRDVYZ5BFJUT15HT5ZNYAZDY53IKDT43J2SFVBSIFSOCQBRWJGYNM55MP2FWT2Q2AHRVGQEMUPQFI0ESFDQQLLPDMFT45CXH4GPFZP-0000000000000012-post
11/12/2015 1:59:27 PM: Status:INFO -- Details=File found: X:-Cerem-InBox-JSBATTIGD-QFTAPDEPLOY-DMP@TPRDVYZ5BFJUT15HT5ZNYAZDY53IKDT43J2SFVBSIFSOCQBRWJGYNM55MP2FWT2Q2AHRVGQEMUPQFI0ESFDQQLLPDMFT45CXH4GPFZP-0000000000000015-post
11/12/2015 1:59:28 PM: Status:INFO -- Details=File found: X:-Cerem-InBox-JSBATTIGD-QFTAPDEPLOY-DMP@TPRDVYZ5BFJUT15HT5ZNYAZDY53IKDT43J2SFVBSIFSOCQBRWJGYNM55MP2FWT2Q2AHRVGQEMUPQFI0ESFDQQLLPDMFT45CXH4GPFZP-0000000000000016-post


Recommendation

Every time you go through a troubleshooting session, after fixing the issue you should think what logging could you have added to accelerate finding the issue in the first place. And when you do that, get it implemented right away in the current sprint or at most in the next sprint.

Tuesday, October 13, 2015

Software Engineering - Naming things

Naming things, maybe one of the toughest things to do in software engineering, and surely the single most important practice of all.

Check this out: http://martinfowler.com/bliki/TwoHardThings.html

Is it not true indeed? Naming things being one of the two hardest thing in software engineering, with the other being cache invalidation?

I believe the power of good naming, or why not, great naming, not only makes software easier to read, maintain and extend, but also simpler to properly craft in the first place.

Good naming exposes intent, and with intent clearly exposed we can see the structure of what we are building and assess if it makes sense or not. Good naming makes refactoring and evolutionary development possible, good naming allows for patterns emergence.

Bad naming typically tends to hide things creating the illusion of "maybe not so bad software" behind the scenes. With bad naming you definitively don't see good software, but worst of all, you may not see terribly bad software hiding under the surface.

So, what's good naming then? I was going to write my own "naming" rules, but I came across these two great articles that do a much better job I could at the task:

http://parallelcross.com/post/36861185276/naming-strategies-uncle-bob-and-ottinger

http://www.objectmentor.com/resources/articles/Naming.pdf

Enjoy

C++ and automatic objects misconceptions

Let's start this blog entry first with a disclaimer: I'm not a expert, not even experienced C++ developer.

Now, I do know a thing or two about C++, and particularly about some of the primitives of the language and not so much about its standard library.

One thing in particular I always liked is the idea of offering developers two models of object allocation:
  • "automatic" objects
  • "explicitly" allocated objects
Before we jump in to automatic objects, just a note on the second bullet point, what I call "explicitly" allocated objects.
The reason I call that model "explicitly" allocated objects rather than let's say, dynamically allocated objects or heap allocated objects is because really the main difference between that model and the "automatic" objects is that the developer tells the compiler with no room for interpretation that a new object will be allocated with memory provided by the new() operator and a particular constructor will be called.
There's no way around it.

Automatic objects, on the other hand, leave a lot of room to the compiler to decide how the final object is going to be provided to the developer.

With that, the motivation of this post is because I see a lot of confusion between C++ developers on exactly how the compiler solves certain constructs, leading to decisions that may not be the most efficient or cleanest ones when crafting code. In all honestly, most of this blog post will be a small piece of code I wrote with some typical and commonly used constructs when creating objects, assigning them to variables and passing them as function parameters. The code I wrote was to answer questions I had myself, in a few cases with assumed answers (that were wrong!) and the C++ compiler surprised positively in every one of the cases.

Without further due, this is the test code:


And this is the console output if you run the program:

vvvvvvv
Example with only one copy of myString class...
myString created
hello 0 my address: 2030296
hello 0 my address: 2030296
myString destroyed
^^^^^^^
vvvvvvv
Even invoking as a constructor creates only one copy...
myString created
hello 1 my address: 2030252
hello 1 my address: 2030252
myString destroyed
^^^^^^^
vvvvvvv
When really copying into an uninitialized object copy constructor is finally use
d...
myString created
hello 2 my address: 2030208
now we will assign str to str2
myString created using copy constructor
hello 2 my address: 2030164
hello 2 my address: 2030208
hello 2 my address: 2030164
myString destroyed
myString destroyed
^^^^^^^
vvvvvvv
What happens if we invoke function that doesn't use & operator?...
myString created
hello 3 my address: 2030120
myString created using copy constructor
hello 3 my address: 2029768
iReceiveAMyString called
myString destroyed
myString destroyed
^^^^^^^
vvvvvvv
When overwriting an object, assignment operator will be called...
myString created
hello A 4 my address: 2030076
myString created
hello B 5 my address: 2030032
let's print str2
hello B 5 my address: 2030032
now we will assign str to str2
myString operator= called
let's print str and after that str2
hello A 4 my address: 2030076
hello A 4 my address: 2030032
myString destroyed
myString destroyed
^^^^^^^

Hopefully it depicts clearly how the C++ compiler is pretty efficient on its dealing with automatic objects. No unnecessary copies, not a single one, even when returning an automatic object from a function the construction storage was the target storage location.

Think very carefully before using new() allocated objects, it may not be worth on many cases. Not to mention you will be incurring typically on expensive heap allocations.

Sunday, March 15, 2015

How to properly support Windows Fibers in Delphi without breaking exception handling

If you are giving a shot to Windows Fibers under Delphi, you probably faced the issue of how to properly handle Delphi's structured exception handling AND switching between fibers transparently.

Assuming you already know what Fibers are, how to use them and when to use them, I will cut to the chase. If you don't know, or don't know enough, I recommend you the following reads to get started:


https://msdn.microsoft.com/en-us/library/windows/desktop/ms682661%28v=vs.85%29.aspx
http://blogs.technet.com/b/markrussinovich/archive/2009/07/08/3261309.aspx


When exceptions happen in a Delphi program, the compiler generates code to store nested exceptions on an exception stack. This stack is stored in a TLS allocated by the program upon startup.

When using Delphi compiled in 32 bits, the issue of persisting and restoring this stack is trivial. Up to the latest versions of Delphi the RTL exposes a couple of functions in the system unit that allow you to do the trick in two lines of code (literally).
The challenge with Delphi programs compiled in 64 bits is that Delphi doesn't expose anymore an API to persist and restore the Exception stack. It's not hard overcome this, but it requires a bit of reverse engineering and watching what the compiler does by enabling the CPU debugger.
I'll spare you from the pain, and below you will find a unit that does the trick:

uWin64ExceptionStack.pas


Here's the full code that I use for switching between fibers:



Before I forget!!!

Here's a sample test that performs a SwitchToFiber() inside an exception handler block. In fact, it's a triple nested exception handler block to test the mechanism of persisting and restored more than just one element of the exception stack.

I hope this helps you on your adventure trying to implement fibers using Delphi.

A note on testing the approach:

Code was verified to work properly on:
Delphi 2007
DelphiXE4 running in WIN32 and WIN64

Special note about Delphi 5. SetRaiseList was totally broken. When used, it will send the application into a tailspin of access violations. See the fixed code, mainly borrowed from Delphi 2007 implementation.

Friday, September 12, 2014

GitHub code reviews etiquette for developers and reviewers

A few months have passed after rolling out our new SDLC process based on Git+GitHub+Jenkins at Convey, I decided to write this post on code reviews etiquette based on the observations I made on what works, what doesn't and the kind of behaviors to stress on developers and reviewers and those behaviors to discourage.

As a bit of a background, before we moved to Git+GitHub, we had our own home-grown version control system and a third party tool we used to drive our process. Our continuous integration system was partially based on standard third party tools and a lot of custom code to stitch the pieces. Everything was beginning to feel dated and inefficient and not so hip anymore.

We needed something newer, better, agile and why not ... also cool.

This was a good opportunity to attack an issue that had bug me for a while since I began to notice that not all developers are created equal (and neither is their code). And, yes, this took me some time to realize. Ok, to put it on more blunt terms: I wanted to attack head on the issue of sub-standard code making it to our central repository, the "golden copy", without any kind of scrutiny whatsoever. Yes, this happened to us, quite a lot and quite often. 
We did mitigate this partially within the last couple of years with after the fact code reviews. It improved the code quality, but was a half-measure in my mind. I would not recommend this to any development leader as the end of the road. 

To solve this persistent issue, for once and for all, we decided to embrace the open source community model based on pull requests from personal forks into a master repo wholeheartedly. I have to tell that this was initially very controversial. Developers were concerned about the scrutiny itself, efficiency, productivity, developers morale, etc. People fear change. We test drove the model for about one year and half with a selected set of projects to gather reactions and tune the process, before we released it to all teams and projects.

If there's something foundational, critical and invaluable that I would not get rid of in our current SDLC, that's the pre-integration code review process built on top of GitHub Pull Requests. That's probably the single and most powerful change we introduced that created the most profound change of behavior within the teams and individual developers.
On this point, I think we have long ways to go yet in terms of developers' maturity to understand what's expected of the pull requests based code review process and how to fully reap the benefits of it for their personal growth as professionals and to improve the company's code base.

This leads me to write these guidelines to make the best out of it:

For developers posting Pull Requests

  1. Post small pull requests. Don't cram together a lot of unrelated changes. Reviewers will find your pull request painful, and two things may happen:
    1. It will get approved very quickly out of "lack of time" (not a good outcome).
    2. They will be ruthless out of being upset on the sheer size and mess of your pull request (not a good outcome either).
  2. If you plan to do a "re-formatting" pull request. Do it on its own, don't mix it up with a feature pull request. Format changes are shown in diffs as every other change, making more painful for reviewers to try to understand the nature of the intended change. Small and limited format changes are OK within the context of a feature pull request.
  3. Post the pull request once you are confident the code works. Hopefully you created automated tests. If automated tests were too expensive to write, at least make sure your code compiles and runs well. Believe, there's nothing more embarrassing that having a compilation syntax error pointed out by a human compiler doing a pull request code review.
  4. Write automated tests. Write automated tests. Write automated tests. Make them part of the pull request. I can't stress it more, and I won't write more about this here when there's plenty of material on the web that outlines in detail the benefits of it.
  5. Answer ALL comments reviewers make to your code. Do it promptly, don't wait days before you reply. Reviewers with merge ability will wait until all issues in the code are addressed. Sometimes addressing them is simply a recognition that you are going to fix the issue later, on another commit. If you don't answer the comments, the pull will remain there open for everyone to see that you don't care.
  6. Be grateful that there's someone out there willing to review your work and provide you feedback. Yes. This IS valuable. It proves that someone cares about what you are doing. Believe me, there's nothing more frustrating that making a pull request on an open source project only to see your work rotting out there with no response from the repo owner. I prefer a blatant rejection of my work than seeing pull requests completely ignored for months.
  7. Don't keep appending changes to an existing pull request that are unrelated to the intent of it. If you start working on a different ticket, create a new branch, commit and open a new pull request based on that branch. If you don't do that, you will be breaking recommendation #1 above.
  8. Before you click the "send" button when creating the pull request, use the opportunity to perform a final review of what you just did. GitHub provides a nice platform to read diffs. Use it.
  9. Finally, don't get upset if a reviewer points out really bad and ugly code you just posted. Don't take comments on code personally. Nobody is making a comment on you, but on the code itself you just posted.

For reviewers/repo owners

  1. If you are on charge of a repo, be prompt to review pull requests. If you are in "reviewing" state, but you don't find specific things to comment on the code, at least write a comment stating you are working on it. That way other reviewers will know there's someone taking care of a particular pull request.
  2. If you don't know exactly what's happening with some piece code, don't be shy and just leave it. Ask questions. I've seen cases where pull requests are approved because there's no developer who really knows what's going on other than the one who wrote the code to begin with. It's really bad when this happens. There's no scrutiny of the logic and the code, and this lends itself for high chances of buggy code getting integrated. At the same time, you can ask other reviewers to check it out and help you with the review. The number of people reviewing the code should be correlated to the complexity and extent of it. This is a case where more prying eyes are better.
  3. Be kind yet candid in your comments. Don't embellish your words if you are meaning to pin point a really bad issue. Just say it. Don't offend the developer but feel free to "offend the code" if necessary. Recognize we all make mistakes. We all have the right to know when we are doing a horrible job, but we want that experience to happen in the context of respect.
  4. If you see people is hesitant to respond to your comments and adopt the social aspect of these code reviews, try posting your comments in the form of questions, such as "I think this be better implemented by... what do you think?". That might inspire people to interact with you via the Pull Request comments feature.
  5. If you find recurring errors/issues in the code, comment each of the instances of the problem, or clearly specify the scope of the review (function, class, file). That will save you from the iterations caused by the developer only fixing the instance you pointed out.
  6. If you find a really awesome piece of code, something you would do an old fashioned paper print out and frame it, just say it on the open with a comment. As much as we tend to focus code reviews to point flaws or ask questions, it's great to praise someone else's clever, smart and creative work. Don't overdo this one. My rule of thumb is to reserve this one for truly remarkable pieces of code.
  7. Just like developers you should answer all comments back. If a developer write back with a comment on something you pin pointed, unless the issue is closed, answer back. This is basic respect for the other.
  8. Once all issues are cleared, and if there's no other impeding aspects, merge the code promptly. There's nothing better for a developer than see their code being accepted into the main repository.
  9. Finally, don't lower your guard!. I see reviewers getting caught on the trap of "feeling too busy for reviews", "deadlines are all over us", "I have no time for this", "It's only one line, I will merge it quick", "we haven't had issues for a while so this must be ok" and all this lame excuses not to conduct proper code reviews. When this happens, code is merged without scrutiny and the possibility of catching issues and maintaining the codebase in good shape is plundered. Reviewers have a responsibility to honor those who created the product that today is in production serving clients. The best way to honor this responsibility is by preventing crappy code of ruining existing working code.

Finally, to be consistent with the principle of what I'm praising in this blog post: the value of pre-integration code reviews, I want to thank Poyo Levin and Rupio Dagum for reviewing the draft of this post, correcting grammatical horrors, pin-pointing typos and suggesting additions that were gladly accepted and incorporated in the final version.

Wednesday, March 5, 2014

Never, ever dismiss the most innocent failing test on your continuousintegration system!

Situation

As part of a project in C that requires some threading primitives, I wrote a piece of code to abstract a Windows timer into a small C class (yes, C class... please don't bash me here for mixing "classes" with plain C code, that will be material for another discussion).

You can find the header file of the basic classes provided by this library here:

https://gist.github.com/jsbattig/9379060

This timer primitive uses Windows threadpool timers. They are kind of nice because they have nothing to do with traditional windows handle linked timers which require a message loop marshaling messages sent to the handle neither they are "multimedia timers". Besides, this library already required thread pools so adding support for threadpool timers was a natural extension to the library itself.

By looking at Windows API documentation I find that to get one of these timers going, besides the fact you need a callback environment variable pre-initialized (or NULL) you need to use the following two APIs:

CreateThreadpoolTimer
SetThreadpoolTimer

SetThreadpoolTimer will actually "start" the timer.

The key parameters this function receives are the timer handle, a "due time" and a recurrence parameter or interval. There's a fourth parameter named msWindowLength which we don't particularly care at this point.

The due time, has the oddity to be the number of units of 100 nanoseconds since January 1, 1601 (UTC) expressed in FILETIME format (I personally found this kind of odd, for a timer... but anyway, MS folks did it like this for some reason I imagine). This parameter, if negative, can also mean a relative time since current time.
The msPeriod parameter is expressed in milliseconds. Why one parameter denoting timer timing in FILETIME and the other in milliseconds? Don't know...

Anyway, at first sight it seemed pretty straightforward, so I crafted the code bellow to get my timer created and going:


So, as you can quickly see, I missed the boat from the get going since I set the FILETIME parameter to be the actual interval in milliseconds converted to 100 nanosecond units since 0 (zero) time.

Here's where Mr Jenkins came to the rescue!
There's a particular test I run to exercise the functioning of this timer:

This test failed once today just before I wrote this blog entry.
This is the GoogleTest jenkins entry for the failure:

c_driver_SSvcBusThreadPoolTest_Win32_Release_singleMongo.SvcBusConsumer_testThreadPoolTimer

 Error Details

Value of: SvcBusThreadPoolTimer_getThreadId( timer)
  Actual: 24652
Expected: 0

 Stack Trace

threadpool_unittest.cc:132
Value of: SvcBusThreadPoolTimer_getThreadId( timer)
  Actual: 24652
Expected: 0

I could have easily dismiss it as a "fluke" or some kind of oddity, maybe the CPU was too busy and the program took to long to go from the creation of the timer to the actual check that's why the threadId recorded was != 0 (even tough the timer was created with 100ms due time).

I don't believe in "oddities" anymore at this point in my career and haven't done so for a while...

So, I dug a little bit to find the obvious which I pretty much imagined since I saw the Jenkins log.

The timer was kicking right away because I pass a positive number not adjusted to January 1st 1601. Now, I did write code to do the adjustment and showed the new working code to a colleague only for him to quickly point me down after checking the documentation why I didn't use the "relative to current" feature. Always good to have another pair of eyes checking at your code to uncover your own naiveness!

So, finally I did that, which by the way it was a really easy solution. All it took was casting the millis parameter to __int64 and negate it. That's it!

Solution

Here's the fixed code:

That's it. That fixes our "oddity", our "cosmic ray flipping that bit to zero", our bad bad Jenkins making our perfectly good code and perfectly written test to fail.

No, there's no oddities, cosmic rays, bad Jenkins or slow CPUs (maybe sometimes there's slow CPUs). A failing test is a failing test, it's signaling something. Either the test is flawed, or there's a bug hiding somewhere behind it.

Happy coding!

Saturday, July 20, 2013

How to make an old Delphi application DEP compatible

The problem


We have an application, our core application, that used to do a couple of things that resulted on DEP violations (read more about it here Data Execution Prevention ).
This two things are:
  • Self patch framework procedures, functions or class methods
  • Generate code during runtime thru scripting engines that perform just-in-time compilation

The solution


Self patching code


Normally developers rely on self patching code when the framework they are utilizing doesn't conform to something they consider should be proper and default behavior, to extend a framework otherwise impossible to modify or to fix a bug on the framework. There might be other reasons I'm omitting here, but these are the most common I've seen. On our case, we pretty much have self-patching code that follow those three descriptions.

Most self patching code uses one variation or another of the same technique, which implies overwriting the first bytes of a procedure to perform a JMP operation of some kind to the new code that replaces the old code.

This is an example of a procedure we use to self-patch code:

procedure PatchMemory(p : Pointer; DataSize : Integer; Data : Pointer; OldData : pointer); 
{$IFNDEF DELPHIXE2}
type
  SIZE_T = DWORD;
{$ENDIF}  
var
  OldProtect : DWORD;
  BytesWritten : SIZE_T;
begin
  VirtualProtect (p, DataSize, PAGE_EXECUTE_READWRITE, OldProtect);
  Move (p^, OldData^, DataSize);
  WriteProcessMemory(GetCurrentProcess, p, Data, DataSize, BytesWritten);
  VirtualProtect (p, DataSize, OldProtect, OldProtect);
end;


The key pieces of the code above are the calls to VirtualProtect() and WriteProcessMemory(). 

Before you overwrite a piece of memory in the code segment, you MUST unprotect the memory using a call to VirtualProtect() with new protection option PAGE_EXECUTE_READWRITE.

The second thing you have to take into consideration is *how* you overwrite the memory on the code segment. I've seen implementations that simply do a move() call with the source and target memory addresses only to see the code fail with DEP violation, even when VirtualProtect() was properly called before.
It's interesting to note that on Microsoft WriteProcessMemory() spec page there's not special note to the fact it's the only way I know of to overwrite a piece of memory on the code segment without getting a DEP violation error.

With a function like the one above, as long as you follow the basic premise of unprotect the memory first and then do patch the memory using WriteProcessMemory() you will be pretty much covered for the typical issue of overwriting the code segment in any other way.


Script engine JIT compilers


Most extensible applications/frameworks rely on some kind of scripting language. From simple yet powerful "configuration" dialects to full blow scripting languages. We use a couple of scripting languages on our programs, both being dialects of Pascal. 
One of this scripting languages is newer and does its job the right way, by allocating the memory for the JIT generated code using VirtualAlloc() passing memory protection attribute PAGE_EXECUTE_READWRITE. That makes the code generated on the heap executable by simply jumping into it.

The older of our scripting engines, simply created a Delphi TMemoryStream object, and wrote into it the generated code. After it was done compiling, it tried to jump into the code generated and that of course failed with a DEP violation.
The problem in this case is that the memory allocated by the Delphi's default memory allocator doesn't use PAGE_EXECUTE_READWRITE, but PAGE_READWRITE. This is fine, and you don't want to change this default behavior

The solution for this particular scripting engine was to replace the default TMemoryStream class, which allocates normal Delphi heap memory, with a descendant of TCustomMemoryStream class which implements it's own memory allocation approach by calling VirtualAlloc() directly with memory protection attribute PAGE_EXECUTE_READWRITE.

Gist for the class: TWinVMMemoryStream


Conclusion


Just by attacking these two problems we made our application DEP compliant.
If you are having a hard time identifying where your non-compliant code might be, my suggestion will be to first try to narrow down when the violations happen.

If violations happen when starting the app, it's likely there self-patching code violations being invoked on the initialization section of unit/modules.

If it happens later down the road, once it's up and running, it's more likely there's some JIT compiler as the culprit.

Anyway, once you know what are the two tricks you have to do:
  • Always call VirtualProtect() before self-patching code, and do it using WriteProcessMemory().
  • Make sure to allocate memory for JIT generated code using VirtualAlloc() with memory protection attribute PAGE_EXECUTE_READWRITE
You will get to DEP compliance in a breeze.

Happy coding!

Friday, July 19, 2013

DLLs deadlocking when getting unloaded if attempting to exit threads

The Problem

At Convey, we use many different languages to construct our solutions, one of them and probably the most commonly used today for a lot of our back-end services is Delphi. 
As any developer with even minor knowledge of Delphi knows, applications based on it are broken up on Units and Units have a "initialization" block of code, and a "finalization" block of code.
Typically these to blocks are utilized to initialize and finalize globals used by each module. These two blocks are guaranteed to be called upon startup/first use of a module and when the module it's going out of scope either by a containing library being unloaded or a program finishing.
Traditionally, developers using other languages such as C rely on explicit calls to initialize or finalize resources on modules... but not in Delphi.

So, this was the root of our problem.

We had code that when compiled and run as part of a standalone EXE or a BPL (Borland Package Library) worked as a charm. Programs started, used the code with no issue and unloaded themselves with no problems. BUT... when the same modules where linked as a part of a DLL, it simply "locked" the program when trying to unload and it was necessary to kill the process for the outside.

Because of this, we ended up relying on all kind of dirty tricks, from leaving memory leaks by prevent freeing resources that "seemed" to cause the freeze to incorporating "auto-kill" code on DLLs that when detected that an app was trying to shutdown it will simply kill the process from the inside.

A while ago I read an article by Chris Wenham ( Signs you are a bad programmer ) and decided that it was time to clean the house to be less of a "bad programmer" according to his definitions. I took on an old thread based timer I wrote many years ago when there no such facility on Windows, but over the years Microsoft added decent timer support. The refactoring resulted on the dreaded DLL deadlocking upon unload of a library which contained the newly refactored timer code.

After some time researching and scratching my head, I came across this article:

Exit thread upon deleting static object during unload DLL causes deadlock?

I decided to go to MSDN to read more about DLL entry point mechanics ( DllMain entry point ) and found this piece of text:
Because DLL notifications are serialized, entry-point functions should not attempt to communicate with other threads or processes. Deadlocks may occur as a result.
Now, that was the first glaring warning sign that I was trying to do something I was not supposed to. The fact I was trying to terminate a job thread on the finalization section of the unit "smelled" to me as "communicating" with other thread on some way.

First thing I tried after that was leaving a resource leak (the actual job threads used by the timer) and that proved to prevent the deadlock from happening.

A second finding as I was experimenting with the finalization section of this unit was that a call to CoUninitialize()causes the same deadlock behavior. And if you read the specs of the function you find this:
Because there is no way to control the order in which in-process servers are loaded or unloaded, do not call CoInitializeCoInitializeEx, or CoUninitializefrom the DllMain function.
Shamefully, without relying on an explicit call from the host application, the only "solution" for the CoUninitialize() limitation is simply to detect the scenario of FreeLibrary() being called and avoid calling the function on the finalization section.

The Solution

So, what do to here? One recommendation will be to make every module or DLL have a couple of exported procedures to Init and Finalize global resources on the DLL. Then you can free your global threads on those procedures. The problem with this approach is that in many cases it might not be possible to modify the host application to adhere to this new protocol, and the second issue I see is that for probably all Delphi developers it's good practice to write code on the finalization section to free global resources without special consideration about all the limitations that DllMain imposes. As said before, under standalone EXE or when using BPLs, no limitations on the finalization code are present that I'm aware of. 

So, I decided to go for something I considered an "elegant hack" (free to interpretation here if there's such a thing as "elegant hacks"...) that will make applications that try to finish a thread on the finalization section of a unit, compatible with DLLs without further modifications other than linking a particular unit that contains the hack on it.

The Code


The first thing I did was to create my own installable custom DllMain handler. This is easy to do with Delphi using the global variable DllProc.

interface
...

var
  ShuttingDownDll : Boolean; // Use this flag to know when a DLL is in DETACH mode
implementation
...

{$IFNDEF DELPHI2007}
type
  THookedDllProc = procedure (Reason: DWORD);
{$ENDIF}

var
  {$IFDEF DELPHI2007}
  OldDllProc : TDLLProc;
  {$ELSE}
  OldDllProc : Pointer;
  {$ENDIF}

// Hooked DllProc used to flag when DLL is being detached
procedure HookedDllProc(Reason: DWORD);
begin
  if not ShuttingDownDll then
    ShuttingDownDll := Reason = DLL_PROCESS_DETACH;
  if assigned(OldDllProc) then
    {$IFNDEF DELPHI2007}THookedDllProc({$ENDIF}OldDllProc{$IFNDEF DELPHI2007}){$ENDIF}(Reason);
end;
initialization
  OldDllProc := DllProc;
  DllProc := @HookedDllProc;
...
finalization
  ...
  DllProc := OldDllProc;
end.

With this now we have the flag ShuttingDownDll set to True when the DLL receives the DLL_PROCESS_DETACH signal.

The second part is the real hack. For this I decided to change the semantics of Delphi EndThread() system procedure. For this I did a simple hack well known on the Delphi community, which involves overwriting the first bytes of the actual code with a relative JMP to the new code.

For this to work you need this:
implementation
...
type
  PJump = ^TJump;
  TJump = packed record
    OpCode:byte;
    Distance:integer;
  end;

var
  OldCode : TJump;
  NewCode : TJump;

procedure HookedEndThread(ExitCode: Integer);
begin
  {$IFDEF DELPHI2007}
  if Assigned(SystemThreadEndProc) then
    SystemThreadEndProc(ExitCode);
  {$ENDIF}
  if (not IsLibrary) or (not ShuttingDownDll) then
    ExitThread(ExitCode)
  else TerminateThread(GetCurrentThread, ExitCode); // Forceful termination of thread if library mode and DLL_PROCESS_DETACH mode
end;

procedure PatchEndThread;
begin
  NewCode.Distance := Integer(@HookedEndThread) - (Integer(@EndThread) + 5);
  PatchMemory (@EndThread, 5, @NewCode, @OldCode);
  FlushInstructionCache (GetCurrentProcess, @EndThread, 5);
end;

procedure UnPatchEndThread;
begin
  PatchMemory (@EndThread, 5, @OldCode);
  FlushInstructionCache (GetCurrentProcess, @EndThread, 5);
end;
initialization
  ...
  NewCode.OpCode := $E9;
  NewCode.Distance := 0;
  PatchEndThread;
  ...
finalization
  ...
  UnPatchEndThread;
  ...
end.

Something to note here is that TerminateThread() doesn't cause the deadlock that ExitThread() causes. It can be assumed that TerminateThread() doesn't attempt to "communicate" with the target thread to be terminated. Of course TerminateThread() is not the same as a clean ExitThread() call, but at least we can get as far as possible following the normal path of execution of the program.

Finally, this is a typical implementation of PatchMemory():


procedure PatchMemory(p : Pointer; DataSize : Integer; Data : Pointer; OldData : pointer); 
{$IFNDEF DELPHIXE2}
type
  SIZE_T = DWORD;
{$ENDIF}  
var
  OldProtect : DWORD;
  BytesWritten : SIZE_T;
begin
  VirtualProtect (p, DataSize, PAGE_EXECUTE_READWRITE, OldProtect);
  Move (p^, OldData^, DataSize);
  WriteProcessMemory(GetCurrentProcess, p, Data, DataSize, BytesWritten);
  VirtualProtect (p, DataSize, OldProtect, OldProtect);
end;


Notice the call to WriteProcessMemory() instead of Delphi's standard Move() procedure. This is key to avoid being caught by Windows DEP protection. Even tough we called VirtualProtect() to make memory writable, DEP doesn't like a process writing anything to the code segment unless it's done using WriteProcessMemory(). If you use that function, you can pretty much overwrite any piece of the code segment as long as you unprotect the memory first.

A caveat with this example is that it's not 64 bits compatible. Obvious things that need to be adjusted are pointer arithmetics and potentially the relative jump used to overwrite ExitThread() ( JMP - Jump ).

Happy coding!