Tuesday, July 16, 2013

Automatic error trace generation in MFlow

To have  the trace of an unexpected error is very important in Web development. Specially when the error has been produced in exploitation. There is no way to make tests in a exploitation environment, so the error message is the only information available to fix it as soon as possible.

Now MFlow permits the creation of execution traces. Not just call traces, but execution traces, whenever an error happens. It uses the package monadloc from Pepe Iborra, used to produce stack traces in his package control-monad-exception

Using MonadLoc, MFlow can produce entire traces instead of call stacks because his backtracking mechanism permits to  run back the execution up to the beginning in case of an exception following the exact execution steps in reverse order. In this back-execution is when the trace is generated. When running normally, the tracing machinery does not affect the performance.

This is an example of what it is necessary in order to have execution traces in case of error.  It is necessary to install the monadloc-pp and monadloc packages that install the monadloc preprocessor and the monadloc class respectively. There are two according changes in the user programs, the preprocessor directive and to include  the Control.Monad.Loc module (in big letters):



This program has an intended error at line 33

  1. {-# OPTIONS -F -pgmF MonadLoc #-}
  2. module TestREST where
  3. import MFlow.Wai.Blaze.Html.All
  4. import Data.Monoid
  5. import Data.String
  6. import Control.Monad.Loc
  7.  
  8.  
  9.  
  10.  
  11. main= runNavigation "" $ transientNav testREST
  12.  
  13.  
  14. testREST= do
  15.   setTimeouts 120 0
  16.   liftIO $ print "start/restart"
  17.  
  18.   setHeader header1
  19.  
  20.   option ←  page $   wlink "a" << p << "letters " <++ p << "or"
  21.                  <|> wlink "1" << p << "numbers"
  22.  
  23.   case option of
  24.     "1"do
  25.           page $ wlink "2" << cont "1"
  26.           page $ wlink "3" << cont "2"
  27.           page $ wlink "4" << cont "3"
  28.           page $ wlink ()  <<  "menu"
  29.  
  30.     "a"do
  31.           page $ wlink "b" << cont "a"
  32.           page $ wlink "c" << cont "b"
  33.           page $ undefined -- wlink "d" << cont "c"
  34.           page $ wlink ()  <<  "menu"
  35.  
  36.  
  37. cont x= p << "page for"
  38.         <> b << x
  39.         <> p << "goto next page"


If we navigate to execute this line with the web browser, the error produced in the console, in the file "errlog" (and in the Web browser if you are logged as administrator) is:

---------------------ERROR-------------------------
TIME=Tue Jul 16 11:52:16 Hora de verano romance 2013

TRACE (error in the last line):

testREST, TestREST(Demos\TestREST.hs): (14, 11)
testREST, TestREST(Demos\TestREST.hs): (20, 3)
testREST, TestREST(Demos\TestREST.hs): (23, 3)
testREST, TestREST(Demos\TestREST.hs): (30, 12)
testREST, TestREST(Demos\TestREST.hs): (31, 11)
testREST, TestREST(Demos\TestREST.hs): (32, 11)
testREST, TestREST(Demos\TestREST.hs): (33, 11)
exception: Prelude.undefined

USER= admin

VERB= navigation

REQUEST:
[("cookieuser","admin"),("flow","1373963274"),("Host","localhost"),("Connection","keep-alive"),("Cache-Control","max-age=0"),("Accept","text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8"),("User-Agent","Mozilla/5.0 (Windows NT 6.2; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/28.0.1500.72 Safari/537.36"),("Accept-Encoding","gzip,deflate,sdch"),("Accept-Language","es-ES,es;q=0.8,en-US;q=0.6"),("Cookie","flow=1373963274; cookieuser=admin")]
 
 
Fine, Isn´t? Note that it is not a call stack, but a true execution trace.
 
If we comment out both lines the error produced is:
 
---------------------ERROR-------------------------
TIME=Tue Jul 16 12:57:04 Hora de verano romance 2013


Prelude.undefined

USER= admin

VERB= navigation

REQUEST:
...
 


How I did that?

Essentially the monadLoc instance permits to add information to a monad about the line number that it is executing now.  I attach in this instance an exception handler to each bind operation so that when a noncaugh exception reaches the handler, it add this line number to  mfTrace, a list of  strings within the internal state monad. Then it trigger a failure that initiates the backtracking (see fail back monad) each step back detect the exception condition because mfTrace is not empty. then each of these steps add its own line to the mfTrace until the execution goes back to the init, were instead of restarting the execution forward, generate a error exception with all the content of mfTrace.

This is the instance:
instance  MonadLoc (FlowM v IO) where
    withLoc loc f = FlowM . BackT $ do
       withLoc loc $ do
            s ←  get
            (r,s') ←  lift $ do
                       (r,s') ←  runWithState f s  `CE.catch` (handler1  loc s)

                       case mfTrace s' of
                            Nothing     →  return (r,s')
                            Just  trace →  return(r, s'{mfTrace= Just( loc:trace)})
            put s'
            return r
       where

       handler1 loc s (e ∷  SomeException)=
        return (GoBack, s{mfTrace= Just ["exception: " ⊕show e]}) 



This is for the MFlow monad. For the View monad, used for in-page flows, the validation fails and mfTrace is filled with the error line, which trigger the backtracking in the MFlow monad.

The code of that last version with traces is not yet in Hackage. In github is at:

 
The fail-back monad is evolving to a supervisor monad that can execute tests, produce error traces , manage exceptional conditions, undo transactions and so on. I have to abstract out this monad from MFlow and make it available as a separate package.

In the next post I promise to talk about it.

I need people interested in MFlow to collaborate !!!!

No comments: