[SOLVED] OS freeze when using debug kernel with CPU Watcher

zzd10h · Post by **zzd10h** » Sun Jun 15, 2014 1:53 pm

Hello,
I'm encountering a strange problem that freezes my whole system when I try to start CPUWatcher (or CPUDock that is based on CPUWatcher) with the debug kernel activated with "MUNGE SERIAL DEBUGLEVEL=5" on CFE.

On my X1000 WITHOUT debug kernel, all is fine, I can start CPUWatcher/CPUDock without problem.

Is this only the X1000 debug kernel who is affected or another systems too freeze in the same circunstance ?

To reproduce :
1) if used, remove CPUDock from your Amidock (LittleBrother too as it seems that it crash with debug kernel too, YAM too when I send 2 mails, at least for me)

2) download CPUWatcher, here :
http://www.os4depot.net/share/utility/w ... atcher.lha

sources available here :
http://www.os4depot.net/share/utility/w ... er-src.lha

3) activate debug kernel in Sys:Kickstart/KickLayout
";MODULE Kickstart/kernel
MODULE Kickstart/kernel.debug"

4) Cold reboot to enable MUNGE SERIAL EBUGLEVEL=5 in CFE, OF or UBOOT
for CFE : setenv -p os4_commandline "MUNGE SERIAL DEBUGLEVEL=5"

5) on OS4, launch several time CPUWatcher from workbench
for me it freezes the first time or the 2nd, 3th time

if you encounter a DSI instead of a freeze, try to increase the stack of CPUWatcher to 100000

6) Could you say me if it freezes your system or not ?

For Raziel and me, it freezes our x1000.
For a SAM460 user, no freeze in the same condition (by increasing the stack size).

Thank you for your time spent on this test, it could be useful for me to know if CPUDock has a bug or not on x1000.

Guillaume

edit : On my serial debug, I have these messages

[[HAL_DfltTrapHandler] *** Warning: Fatal exception in task 0x518F5A30
(Uuno, etask = 0xDFD029A0) at ip 0x7F9BB678
[HAL_Alert] ALERT! 0x80000003
Dump of context at 0xDF6B7000
Trap type: DSI exception
Machine State (raw): 0x1000000000003032
Machine State (verbose): [Hyper] [Super] [FPU on] [IAT on] [DAT on]
[Recoverable]
Temporary stack trace:
#0: 0x7F9BB678
#1: in module kernel.debug+0x00004BA4 (0x02004BA4)

Crashed task: UunoskWithUpdate] Aborting to prevent infinite recursion
[HAL_DfltTrapHandler] *** Warning: Fatal exception in task 0x518F5A30
(Uuno, etask = 0xDFD029A0) at ip 0x7F9BB678
[HAL_Alert] ALERT! 0x80000003
[HAL_SuspendTaskWithUpdate] *** Warning: Suspending an already suspended
task
[HAL_SuspendTaskWithUpdate] Aborting to prevent infinite
recursionrapHandler] *** Warning: Fatal exception in task 0x518F5A30
(Uuno, etask = 0xDFD029A0) at ip 0x7F9BB678
[HAL_Alert] ALERT! 0x80000003
[HAL_SuspendTaskWithUpdate] *** Warning: Suspending an already suspended
task
[HAL_SuspendTaskWithUpdate] Aborting to prevent infinite
recursion
...
... in loop until I poweroff my x1000
...
[HAL_DfltTrapHandler] *** Warning:on i task 0x518F5A30 (Uuno, etask =
0xDFD029A0) at ip 0x7F9BB678
[HAL_Alert] ALRT! 0x80000003
[HAL_SuspendTaskWithUpdate] *** Warning: Suspending an already suspended
task
[HAL_SuspendTaskWithUpdate] Aborting to prevent infinite
recursion

Raziel · Post by **Raziel** » Sun Jun 15, 2014 3:02 pm

...and to keep every possible information in one place, here are my two crashlogs (captured over serial because it froze solid)

X1000 here: SERIAL MUNGE DEBGUGLEVEL=5 set and using kernel.debug

Serial log with CPUWatcher

Hidden Text - Click to Show :

Serial log with CPUDock.docky

Hidden Text - Click to Show :

Both of them caught either adding/removing to AmiDock (CPUDock.docky) or starting/closing on Workbench (CPUWatcher)

As you can see it's the exact same crash (that's good because it's based on the same code)

Now to find that piece of offending code...

Once (because it only freeze in one of three tries) the docky was added to AmiDock it will freeze 75% of the reboots, so it's a severe problem for me (uninstalled the docky for now)

Post by **Thomas Frieden** » Sun Jun 15, 2014 3:37 pm

The amount of ABADCAFE in the log somewhat points to usage of uninitialized memory

Sent from my Xperia Z1

zzd10h · Post by **zzd10h** » Sun Jun 15, 2014 3:48 pm

Thank you for your reply,

yes, but why does it works on a non debug kernel and, overall, why does it seems to work on a SAM460 with the debug kernel ?

Raziel · Post by **Raziel** » Sun Jun 15, 2014 9:38 pm

Little update...

I have taken out MUNGE from my os4_commandline as it seems to produce lots of random errors/crashes with random programs.
Those are gone after MUNGE was removed.

It still freezes when using the debug kernel though

Post by **javierdlr** » Wed Jun 18, 2014 12:09 am

Seems Guillaume solved by adding 'Delay(1)' before 'FindTask(NULL)', maybe some kind of timing race condition on X1000 systems?
On my SAM460ex I can't make it fail/crash.

CPU.C source code ("main" code from CPUwatcher/CPUDocky):

Hidden Text - Click to Show :

Code: Select all

;/* CPU functions
gcc -Wall -N -gstabs -O2 -o cpu cpu.c
quit
*/

#include <proto/exec.h>
#include <proto/dos.h>
#include <proto/timer.h>

static __attribute__((used)) char *version_string = "$VER: CPU 0.1beta (18.11.2013)";

struct ExecIFace *IExec;
struct Device *TimerBase;
struct TimerIFace *ITimer;
struct DOSIFace *IDOS;

APTR idlerMx; // using mutex instead of Forbid/Permit

// Signals for inter-process synchronization
static ULONG idle_sig = -1, main_sig = -1;
// Main task's address
static struct Task *main_task;
// "Volatile" to avoid clever optimizer walking over me. Program runs as long as flag is set.
static volatile BOOL running = TRUE;
// Simple mode switches to non-busy looping option when measuring the CPU usage.
static volatile BOOL simple_mode = TRUE;
// How many times idle task was ran during 1 second. Run count 0 means 100% cpu usage, 100 means 0 % CPU usage
static uint32 run_count = 0;
// Used by idle task for 1/100 second pauses when running in non-busy looping mode
static struct TimeRequest *pause_req = NULL;
// For keeping book of time
static struct TimeVal idle_start, idle_finish, idle_time;


// Idle task gives up CPU
static void my_switch(void)
{
 ITimer->GetSysTime(&idle_finish);

 ITimer->SubTime(&idle_finish, &idle_start);

 idle_time.Seconds += idle_finish.Seconds;
 idle_time.Microseconds += idle_finish.Microseconds;
}


// Idle task gets CPU
static void my_launch(void)
{
 ITimer->GetSysTime(&idle_start);
}


// Set if idler task runs into trouble
static BOOL error = FALSE;

/* Idler process. Soon after creation its priority is dropped to minimal so that it can't disturb the system */
static void idler(void)
{
 struct Task *me = NULL;
 struct MsgPort *idle_port = IExec->AllocSysObject(ASOT_PORT, NULL); // Message port for our timerequest
 if(!idle_port)
 {
  error = TRUE;
  goto die;
 }

 idle_sig = IExec->AllocSignal(-1);
 if(idle_sig == -1)
 {
  error = TRUE;
  goto die;
 }

//IDOS->Printf("Avant Delay() \n");
IDOS->Delay(1);
//IDOS->Printf("Aprés Delay() \n");

 me = IExec->FindTask(NULL);

 // And god kills another kitten...
 //IExec->Forbid();
 IExec->MutexObtain(idlerMx);
 me->tc_Switch = my_switch;
 me->tc_Launch = my_launch;
 me->tc_Flags |= TF_SWITCH | TF_LAUNCH;
 //Permit();
 IExec->MutexRelease(idlerMx);

 // Signal main task that we are ready
 IExec->Signal(main_task, 1L<<main_sig);

 // Wait for main task to obtain ITimer
 IExec->Wait(1L<<idle_sig);

 pause_req->Request.io_Message.mn_ReplyPort = idle_port;

 // Let's be reasonable...
 IExec->SetTaskPri(IExec->FindTask(NULL), -127);

 // If running wasn't volatile, optimizer would disable test!
 while(running)
 {
  // When in "Simple" mode, pause for 1/100th of second
  if(simple_mode) // Toggle TRUE/FALSE not yet implemented (default is TRUE)
  {
   struct TimeVal tv;

   run_count++;

   ITimer->GetSysTime(&tv);

   tv.Microseconds += 10000; // 100 Hz

   pause_req->Request.io_Command = TR_ADDREQUEST;
   pause_req->Time.Seconds = tv.Seconds;
   pause_req->Time.Microseconds = tv.Microseconds;

   // Set the timer running
   IExec->DoIO( (struct IORequest *)pause_req );
  }
 }

 //Forbid();
 IExec->MutexObtain(idlerMx);
 me->tc_Switch = NULL;
 me->tc_Launch = NULL;
 me->tc_Flags ^= TF_SWITCH | TF_LAUNCH;
 //Permit();
 IExec->MutexRelease(idlerMx);

 if(idle_sig != -1)
  IExec->FreeSignal(idle_sig);

die:
 if(idle_port)
  IExec->FreeSysObject(ASOT_PORT, idle_port);

 // Tell the main task that we can leave now (error flag may be set!)
 IExec->Signal(main_task, 1L << main_sig);

 // Waiting for termination, Valhalla awaits!
 IExec->Wait(0L);
}


/********/
/* MAIN */
/********/
int main(void)
{
 struct MsgPort *timer_port = NULL;
 struct TimeRequest *timer_req = NULL;
 struct Task *idle_task = NULL;
 BYTE timer_device = -1;

 idlerMx = IExec->AllocSysObjectTags(ASOT_MUTEX, /*ASOMUTEX_Recursive,FALSE,*/ TAG_END);

 main_sig = IExec->AllocSignal(-1);
 if(main_sig == -1)
 {
  IDOS->Printf("Couldn't allocate main signal\n");
  goto clean;
 }

 // Who was I again? Hmm...
 main_task = IExec->FindTask(NULL);

 // Spawn a little nasty minion
 idle_task = IExec->CreateTaskTags("CPU_idleTask", 0, idler, 16384, CT_LockStack,TRUE, TAG_DONE);
 if(idle_task)
 {
  timer_port = IExec->AllocSysObject(ASOT_PORT, NULL);
  if(timer_port)
  {
   timer_req = IExec->AllocSysObjectTags(ASOT_IOREQUEST,
                                         ASOIOR_Size, sizeof(struct TimeRequest),
                                         ASOIOR_ReplyPort, timer_port,
                                        TAG_END);

   if(timer_req)
   {
    if( !(timer_device=IExec->OpenDevice("timer.device", UNIT_WAITUNTIL, (struct IORequest *)timer_req, 0)) )
    {
     TimerBase = (struct Device *)timer_req->Request.io_Device;
     ITimer = (struct TimerIFace *)IExec->GetInterface( (struct Library *)TimerBase, "main", 1, NULL );
     pause_req = IExec->AllocVecTags(sizeof(struct TimeRequest), AVT_ClearWithValue,0, TAG_DONE);
     if(!pause_req)
      goto clean;

     IExec->CopyMem( timer_req, pause_req, sizeof(struct TimeRequest) );

     if(ITimer)
     {
      struct TimeVal tv;

      // Let's sync to idler task now
      IExec->Wait(1L<<main_sig);

      if(error)
       goto clean;

      // Send message, "We've got ITimer now", back
      IExec->Signal(idle_task, 1L<<idle_sig);

      ITimer->GetSysTime(&tv);

      tv.Seconds++;
//IDOS->Printf("1)tv.Seconds=%ld\n",tv.Seconds);
      timer_req->Request.io_Command = TR_ADDREQUEST;
      timer_req->Time.Seconds = tv.Seconds;
      timer_req->Time.Microseconds = tv.Microseconds;

      // Set the timer running
      IExec->SendIO( (struct IORequest *)timer_req );

      // Reset idle time
      idle_time.Seconds = 0;
      idle_time.Microseconds = 0;

      // The Main Loop
      while(running)
      {
       ULONG sigs = IExec->Wait(SIGBREAKF_CTRL_C | 1L<<timer_port->mp_SigBit);

       // Handle timer events
       if( sigs&(1L<<timer_port->mp_SigBit) )
       {
        IExec->GetMsg(timer_port);

        tv.Seconds++;
//IDOS->Printf("2)tv.Seconds=%ld\n",tv.Seconds);
        timer_req->Request.io_Command = TR_ADDREQUEST;
        timer_req->Time.Seconds = tv.Seconds;
        timer_req->Time.Microseconds = tv.Microseconds;

        IExec->SendIO( (struct IORequest *)timer_req );

        // Timer signal, update visuals once per second
        //if( (++count % FREQ) == 0 ) // FREQ?
        {
         uint16 value = 100;

         if(simple_mode) // Toggle TRUE/FALSE not yet implemented (default is TRUE)
         {
          value -= run_count;
          IDOS->Printf("CPU:%ld%% (%ld) S ",value,run_count);
         }
         else
         {
          value -= 100 * (idle_time.Seconds * 1000000 + idle_time.Microseconds) / 1000000.0;
          IDOS->Printf("CPU:%ld%% (%ld) B ",value,run_count);
         }

         // Reset idle time
         idle_time.Seconds = 0;
         idle_time.Microseconds = 0;
         run_count = 0;

         if(value > 100)
          value = 100;

//         cpu[ ++iter % XSIZE ] = value; // cpu graph data

         IDOS->FFlush( IDOS->Output() );
         IDOS->Printf("\r\033[K");
        }

       }
       // Handle Control-C too
       if(sigs&SIGBREAKF_CTRL_C)
        running = FALSE;
      }
     }

     if( !IExec->CheckIO((struct IORequest *)timer_req) )
     {
      IExec->AbortIO( (struct IORequest *)timer_req );
      while( IExec->GetMsg(timer_port) );
     }

    }
    else
     IDOS->Printf("Couldn't open timer.device\n");

   }
  }

 }
 else
  IDOS->Printf("Couldn't create idler task\n");

clean:
 // if idler task had problems, don't wait for it
 if(idle_task && !error)
 {
  // Give it some more cpu
  IExec->SetTaskPri(idle_task, 0);
  // Wait idler task to finish possible timer actions before closing timing services
  IExec->Wait(1L<<main_sig | SIGBREAKF_CTRL_C);
 }

 if(ITimer)
  IExec->DropInterface( (struct Interface *)ITimer );

 if(timer_device==0 && timer_req)
  IExec->CloseDevice( (struct IORequest *)timer_req );

 if(timer_req)
  IExec->FreeSysObject(ASOT_IOREQUEST, timer_req);

 if(pause_req)
  IExec->FreeVec(pause_req);

 if(timer_port)
  IExec->FreeSysObject(ASOT_PORT, timer_port);

 if(idle_task)
  IExec->DeleteTask(idle_task); // Farewell, idler!

 if(main_sig != -1)
  IExec->FreeSignal(main_sig);

 IExec->FreeSysObject(ASOT_MUTEX, idlerMx);

return 0;
}

Post by **Thomas Frieden** » Wed Jun 18, 2014 3:03 pm

zzd10h wrote:Thank you for your reply,

yes, but why does it works on a non debug kernel and, overall, why does it seems to work on a SAM460 with the debug kernel ?

The non-debug kernel does not munge memory, and it does not destroy linkage in removed list nodes. The debug kernel does, for the exact purpose of exposing bugs.

Why it works with a sam460 is unknown, but the very nature of the bugs that mungin and/or link destruction exposes is their randomness. Besides, the usualy munging patters have like 0xabadcafe and 0xcccccccc (for list destruction) will work on teh sam460 since these areas are mapped on the 460 (chip registers)

Post by **Thomas Frieden** » Wed Jun 18, 2014 3:14 pm

javierdlr wrote:Seems Guillaume solved by adding 'Delay(1)' before 'FindTask(NULL)', maybe some kind of timing race condition on X1000 systems?

I doubt that this would only exhibit in such rare cases. Besides, the Delay probably just makes it gloss over the freed memory.

Just to make sure, you are NOT using an X-kernel ?

Post by **ssolie** » Wed Jun 18, 2014 6:44 pm

Thomas Frieden wrote:The non-debug kernel does not munge memory, and it does not destroy linkage in removed list nodes. The debug kernel does, for the exact purpose of exposing bugs.

Why it works with a sam460 is unknown, but the very nature of the bugs that mungin and/or link destruction exposes is their randomness. Besides, the usualy munging patters have like 0xabadcafe and 0xcccccccc (for list destruction) will work on teh sam460 since these areas are mapped on the 460 (chip registers)

@all
Note that we have some more detailed information about the debug kernel on the wiki at
http://wiki.amigaos.net/wiki/Debug_Kernel

zzd10h · Post by **zzd10h** » Wed Jun 18, 2014 9:23 pm

@Thomas Frieden
Thank you for the explanation,
I will continue to investigate with Javier, Raziel and the AmiOuest France team

Hyperion Entertainment Message Boards

[SOLVED] OS freeze when using debug kernel with CPU Watcher

[SOLVED] OS freeze when using debug kernel with CPU Watcher

Re: OS freeze when using debug kernel with CPU Watcher

Re: OS freeze when using debug kernel with CPU Watcher

Re: OS freeze when using debug kernel with CPU Watcher

Re: OS freeze when using debug kernel with CPU Watcher

Re: OS freeze when using debug kernel with CPU Watcher

Re: OS freeze when using debug kernel with CPU Watcher

Re: OS freeze when using debug kernel with CPU Watcher

Re: OS freeze when using debug kernel with CPU Watcher

Re: OS freeze when using debug kernel with CPU Watcher