Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Different Behaviour Unwinding Stack in x64 and x32

Why in the scenario detailed below does the stack space increase in x64 but decrease in x32 with identical code?

Background:

Our customers can write scripts in a domain language which is interpretted at runtime using a recursive technique and executed on a web server. It's possible that they might make a mistake in the script which throws an exception, this exception gets caught and logged.

Because of this recursive technique, we guard against stack overflow exceptions by checking the stack space used as the interpretter executes the script, and terminating the script before we actually run out of stack.

In 32bit mode everything works well, when the scripter makes an error an Exception is generated, it's logged, the stack unwinds during which the space left on the stack increases and the script is terminated nicely.

In 64bit mode everything is not so good, when the scripter makes an error an Exception is generated, it's logged, the stack unwinds during which the space left on the stack decreases. This is very bad because there is a possibility that if the script happens to have used a lot of stack space and throws then the act of unwinding the stack and logging the error itself causes a StackOverflowException which hides the original exception, hoses IIS, and kills all the inflight requests (bad, very bad and really really bad).

Recreating the problem:

Here's a console app which models the code I use in production and recreates the problem when set to x64, and works fine in x32.

using System;
using System.ComponentModel;
using System.Runtime.InteropServices;

namespace ConsoleApplication16
{
    class Program
    {
        const Int32 MaxNumberRecursions = 10;
        static Int32 _currentRecursionDepth;
        static UInt64 _lastSpaceUsed;

        static void Main(string[] args)
        {
            System.Diagnostics.Debug.WriteLine(String.Format("Is64BitProcess = {0}", System.Environment.Is64BitProcess));
            try
            {
                _lastSpaceUsed = GetStackBytesLeft();
                RecurseXTimes();
            }
            catch (Exception e)
            {
                System.Diagnostics.Debug.WriteLine(e);
            }
        }

        unsafe static void RecurseXTimes()
        {
            System.Diagnostics.Debug.WriteLine("--> RecurseXTimes()");
            ReportStackSpaceUsage();

            try
            {
                _currentRecursionDepth++;
                if (_currentRecursionDepth > MaxNumberRecursions)
                {
                    throw new Exception("Please unwind my stack");
                }

                System.Diagnostics.Debug.WriteLine(String.Format("Adding {0} bytes to stack.", sizeof(SomeDataToUseUpSomeStackSpace)));                
                SomeDataToUseUpSomeStackSpace someDataToUseUpSomeStackSpace = new SomeDataToUseUpSomeStackSpace();

                RecurseXTimes();
            }
            catch(Exception e)
            {
                //Do some logging. NOTE taking this "catch" out "fixes" the problem, but I can't do this in prod.
                System.Diagnostics.Debug.WriteLine(e.Message);
                throw;
            }
            finally
            {
                ReportStackSpaceUsage();
                System.Diagnostics.Debug.WriteLine("<-- RecurseXTimes()");
            }
        }

        private static void ReportStackSpaceUsage()
        {
            UInt64 stackUsed = GetStackBytesLeft();
            Int64 stackSpaceDelta = (Int64) stackUsed - (Int64) _lastSpaceUsed;
            Int64 stackSpaceDeltaAbs = Math.Abs(stackSpaceDelta);

            System.Diagnostics.Debug.WriteLine(
                String.Format("Stack space left: {0}. Stack Space Delta: {1} {2}", 
                                stackUsed,
                                stackSpaceDeltaAbs,
                                stackSpaceDelta < 0 ? "Allocated On Stack" : "Freed from Stack"));

            _lastSpaceUsed = stackUsed;
        }


        static unsafe ulong GetStackBytesLeft()
        {
            MEMORY_BASIC_INFORMATION stackInfo = new MEMORY_BASIC_INFORMATION();
            UIntPtr currentAddr = new UIntPtr(&stackInfo);
            int sizeT = VirtualQuery(currentAddr, ref stackInfo, sizeof(MEMORY_BASIC_INFORMATION));

            if (sizeT == 0)
            {
                //No Data Returned
                int lastError = Marshal.GetLastWin32Error();
                throw new Win32Exception(lastError);
            }

            UInt64 stackBytesLeft = currentAddr.ToUInt64() - stackInfo.AllocationBase.ToUInt64();
            return stackBytesLeft;
        }

        [DllImport("kernel32.dll", SetLastError = true)]
        static extern int VirtualQuery(UIntPtr lpAddress, ref MEMORY_BASIC_INFORMATION lpBuffer, int dwLength);

        [StructLayout(LayoutKind.Sequential)]
        struct MEMORY_BASIC_INFORMATION
        {
            public UIntPtr BaseAddress;
            public UIntPtr AllocationBase;
            public uint AllocationProtect;
            public UIntPtr RegionSize;
            public uint State;
            public uint Protect;
            public uint Type;
        };

        private struct SomeDataToUseUpSomeStackSpace
        {
            public Int64 a0, a1, a2, a3, a4, a5, a6, a7, a8, a9, a10, a11, a12, a13, a14, a15, a16, a17, a18, a19, a20, a21, a22, a23, a24, a25;
            public Int64 b0, b1, b2, b3, b4, b5, b6, b7, b8, b9, b10, b11, b12, b13, b14, b15, b16, b17, b18, b19, b20, b21, b22, b23, b24, b25;
            public Int64 c0, c1, c2, c3, c4, c5, c6, c7, c8, c9, c10, c11, c12, c13, c14, c15, c16, c17, c18, c19, c20, c21, c22, c23, c24, c25;
            public Int64 d0, d1, d2, d3, d4, d5, d6, d7, d8, d9, d10, d11, d12, d13, d14, d15, d16, d17, d18, d19, d20, d21, d22, d23, d24, d25;
            public Int64 e0, e1, e2, e3, e4, e5, e6, e7, e8, e9, e10, e11, e12, e13, e14, e15, e16, e17, e18, e19, e20, e21, e22, e23, e24, e25;
            public Int64 f0, f1, f2, f3, f4, f5, f6, f7, f8, f9, f10, f11, f12, f13, f14, f15, f16, f17, f18, f19, f20, f21, f22, f23, f24, f25;
            public Int64 g0, g1, g2, g3, g4, g5, g6, g7, g8, g9, g10, g11, g12, g13, g14, g15, g16, g17, g18, g19, g20, g21, g22, g23, g24, g25;
            public Int64 h0, h1, h2, h3, h4, h5, h6, h7, h8, h9, h10, h11, h12, h13, h14, h15, h16, h17, h18, h19, h20, h21, h22, h23, h24, h25;
            public Int64 i0, i1, i2, i3, i4, i5, i6, i7, i8, i9, i10, i11, i12, i13, i14, i15, i16, i17, i18, i19, i20, i21, i22, i23, i24, i25;
            public Int64 j0, j1, j2, j3, j4, j5, j6, j7, j8, j9, j10, j11, j12, j13, j14, j15, j16, j17, j18, j19, j20, j21, j22, j23, j24, j25;
            public Int64 k0, k1, k2, k3, k4, k5, k6, k7, k8, k9, k10, k11, k12, k13, k14, k15, k16, k17, k18, k19, k20, k21, k22, k23, k24, k25;
            public Int64 l0, l1, l2, l3, l4, l5, l6, l7, l8, l9, l10, l11, l12, l13, l14, l15, l16, l17, l18, l19, l20, l21, l22, l23, l24, l25;
            public Int64 m0, m1, m2, m3, m4, m5, m6, m7, m8, m9, m10, m11, m12, m13, m14, m15, m16, m17, m18, m19, m20, m21, m22, m23, m24, m25;
            public Int64 n0, n1, n2, n3, n4, n5, n6, n7, n8, n9, n10, n11, n12, n13, n14, n15, n16, n17, n18, n19, n20, n21, n22, n23, n24, n25;
            public Int64 o0, o1, o2, o3, o4, o5, o6, o7, o8, o9, o10, o11, o12, o13, o14, o15, o16, o17, o18, o19, o20, o21, o22, o23, o24, o25;
            public Int64 p0, p1, p2, p3, p4, p5, p6, p7, p8, p9, p10, p11, p12, p13, p14, p15, p16, p17, p18, p19, p20, p21, p22, p23, p24, p25;
            public Int64 q0, q1, q2, q3, q4, q5, q6, q7, q8, q9, q10, q11, q12, q13, q14, q15, q16, q17, q18, q19, q20, q21, q22, q23, q24, q25;
            public Int64 r0, r1, r2, r3, r4, r5, r6, r7, r8, r9, r10, r11, r12, r13, r14, r15, r16, r17, r18, r19, r20, r21, r22, r23, r24, r25;
            public Int64 s0, s1, s2, s3, s4, s5, s6, s7, s8, s9, s10, s11, s12, s13, s14, s15, s16, s17, s18, s19, s20, s21, s22, s23, s24, s25;
            public Int64 t0, t1, t2, t3, t4, t5, t6, t7, t8, t9, t10, t11, t12, t13, t14, t15, t16, t17, t18, t19, t20, t21, t22, t23, t24, t25;
            public Int64 u0, u1, u2, u3, u4, u5, u6, u7, u8, u9, u10, u11, u12, u13, u14, u15, u16, u17, u18, u19, u20, u21, u22, u23, u24, u25;
            public Int64 v0, v1, v2, v3, v4, v5, v6, v7, v8, v9, v10, v11, v12, v13, v14, v15, v16, v17, v18, v19, v20, v21, v22, v23, v24, v25;
            public Int64 w0, w1, w2, w3, w4, w5, w6, w7, w8, w9, w10, w11, w12, w13, w14, w15, w16, w17, w18, w19, w20, w21, w22, w23, w24, w25;
            public Int64 x0, x1, x2, x3, x4, x5, x6, x7, x8, x9, x10, x11, x12, x13, x14, x15, x16, x17, x18, x19, x20, x21, x22, x23, x24, x25;
            public Int64 y0, y1, y2, y3, y4, y5, y6, y7, y8, y9, y10, y11, y12, y13, y14, y15, y16, y17, y18, y19, y20, y21, y22, y23, y24, y25;
            public Int64 z0, z1, z2, z3, z4, z5, z6, z7, z8, z9, z10, z11, z12, z13, z14, z15, z16, z17, z18, z19, z20, z21, z22, z23, z24, z25;
        }
    }
}

Example Output:

x32 - everything is dandy, stack space decreases whist descending, and increases during unwinding.

Is64BitProcess = False
--> RecurseXTimes()
Stack space left: 1036512. Stack Space Delta: 5652 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 1031004. Stack Space Delta: 5508 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 1025496. Stack Space Delta: 5508 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 1019988. Stack Space Delta: 5508 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 1014480. Stack Space Delta: 5508 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 1008972. Stack Space Delta: 5508 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 1003464. Stack Space Delta: 5508 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 997956. Stack Space Delta: 5508 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 992448. Stack Space Delta: 5508 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 986940. Stack Space Delta: 5508 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 981432. Stack Space Delta: 5508 Allocated On Stack
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
Please unwind my stack
Stack space left: 976816. Stack Space Delta: 4616 Allocated On Stack
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
<-- RecurseXTimes()
Please unwind my stack
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
Stack space left: 982328. Stack Space Delta: 5512 Freed from Stack
<-- RecurseXTimes()
Please unwind my stack
Stack space left: 987832. Stack Space Delta: 5504 Freed from Stack
<-- RecurseXTimes()
Please unwind my stack
Stack space left: 993344. Stack Space Delta: 5512 Freed from Stack
<-- RecurseXTimes()
Please unwind my stack
Stack space left: 998848. Stack Space Delta: 5504 Freed from Stack
<-- RecurseXTimes()
Please unwind my stack
Stack space left: 1004360. Stack Space Delta: 5512 Freed from Stack
<-- RecurseXTimes()
Please unwind my stack
Stack space left: 1009864. Stack Space Delta: 5504 Freed from Stack
<-- RecurseXTimes()
Please unwind my stack
Stack space left: 1015376. Stack Space Delta: 5512 Freed from Stack
<-- RecurseXTimes()
Please unwind my stack
Stack space left: 1020880. Stack Space Delta: 5504 Freed from Stack
<-- RecurseXTimes()
Please unwind my stack
Stack space left: 1026392. Stack Space Delta: 5512 Freed from Stack
<-- RecurseXTimes()
Please unwind my stack
Stack space left: 1031896. Stack Space Delta: 5504 Freed from Stack
<-- RecurseXTimes()
System.Exception: Please unwind my stack

Here's the output with exactly the same code in x64, stack space increases whilst decending, but keeps on decreasing during unwinding:

Is64BitProcess = True
--> RecurseXTimes()
Stack space left: 1034256. Stack Space Delta: 5696 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 1028704. Stack Space Delta: 5552 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 1023152. Stack Space Delta: 5552 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 1017600. Stack Space Delta: 5552 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 1012048. Stack Space Delta: 5552 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 1006496. Stack Space Delta: 5552 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 1000944. Stack Space Delta: 5552 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 995392. Stack Space Delta: 5552 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 989840. Stack Space Delta: 5552 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 984288. Stack Space Delta: 5552 Allocated On Stack
Adding 5408 bytes to stack.
--> RecurseXTimes()
Stack space left: 978736. Stack Space Delta: 5552 Allocated On Stack
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
Please unwind my stack
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
Stack space left: 957392. Stack Space Delta: 21344 Allocated On Stack
<-- RecurseXTimes()
Please unwind my stack
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
Stack space left: 948880. Stack Space Delta: 8512 Allocated On Stack
<-- RecurseXTimes()
Please unwind my stack
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
Stack space left: 940368. Stack Space Delta: 8512 Allocated On Stack
<-- RecurseXTimes()
Please unwind my stack
Stack space left: 931856. Stack Space Delta: 8512 Allocated On Stack
<-- RecurseXTimes()
Please unwind my stack
Stack space left: 923344. Stack Space Delta: 8512 Allocated On Stack
<-- RecurseXTimes()
Please unwind my stack
Stack space left: 914832. Stack Space Delta: 8512 Allocated On Stack
<-- RecurseXTimes()
Please unwind my stack
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
Stack space left: 906320. Stack Space Delta: 8512 Allocated On Stack
<-- RecurseXTimes()
Please unwind my stack
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
Stack space left: 897808. Stack Space Delta: 8512 Allocated On Stack
<-- RecurseXTimes()
Please unwind my stack
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
Stack space left: 889296. Stack Space Delta: 8512 Allocated On Stack
<-- RecurseXTimes()
Please unwind my stack
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
Stack space left: 880784. Stack Space Delta: 8512 Allocated On Stack
<-- RecurseXTimes()
Please unwind my stack
A first chance exception of type 'System.Exception' occurred in ConsoleApplication16.exe
Stack space left: 872272. Stack Space Delta: 8512 Allocated On Stack
<-- RecurseXTimes()
System.Exception: Please unwind my stack

Curiously enough, if I remove the "Catch" then under 64 bit it keeps the stack used the same - but I can't do this in prodcuction because I need to do logging in the catch.

like image 562
Daniel James Bryars Avatar asked Feb 29 '12 15:02

Daniel James Bryars


1 Answers

It seems that the extra block of memory is being allocated when you re-throw the exception. So you can still catch it in your production code.

Extensive research (well a google really) shows that x64 stack unwind metadata might be the cuplrit for the extra allocations in x64 mode.

I changed the exception catch in RecurseXTimes in your sample code so that it:

  • Logs the exception as currently
  • Serializes it via BinaryFormatter

And at the end of the following finally Deserialze and throw it. The stack unwind traces now look pretty similar between 32 and 64 bit mode.

Ok so you lose visibility of the exception site but its recursive anyway so at least the function name is right.. and you might have to sort out how you can allocate enough memory to serialize it!

[Edit] Here's the tweak I did:

        catch (Exception e)
        {
            //Do some logging. NOTE taking this "catch" out "fixes" the problem, but I can't do this in prod.
            System.Diagnostics.Debug.WriteLine(e.Message);
            caughtException = new MemoryStream();
            BinaryFormatter exceptionFormatter = new BinaryFormatter(); // Exception raised on this line
            exceptionFormatter.Serialize(caughtException, e);
            caughtException.Seek(0, SeekOrigin.Begin);
        }
        finally
        {
            ReportStackSpaceUsage();
            System.Diagnostics.Debug.WriteLine("<-- RecurseXTimes()");
            if (caughtException != null)
            {
                BinaryFormatter exceptionFormatter = new BinaryFormatter();
                Exception e = (Exception)exceptionFormatter.Deserialize(caughtException);
                throw e;
            }
        }

Hopefully in your real app there is enough headroom to do this without a secondary OutOfMemoryException.

like image 52
Peter Wishart Avatar answered Sep 30 '22 01:09

Peter Wishart