"No clock movement" error

Here you can post threads on the development of the current beta releases of the core (099)

Moderator: POL Developer

Post Reply
RusseL
Forum Regular
Posts: 333
Joined: Fri Feb 20, 2009 8:30 pm

"No clock movement" error

Post by RusseL » Sat Jul 01, 2017 7:19 am

Does anyone have an idea how to debug such errors? pol freezes completely and can not be turned off properly...
and, as i understand, it's not an error in script... this script runs successfully already over 10 years :)

Code: Select all

scpt: 737334  task: 63(0)  scin: 1758991  scsl: 2710951307  MOB: 3459  TLI: 65645
Client disconnected from 188.226.30.94 (11 connections)
Account Maza_Faka logged in from 188.226.30.94
Client disconnected from 188.226.30.94 (11 connections)
sysload=1 (0) cputime=0
scpt: 728803  task: 62(0)  scin: 1742074  scsl: 2677803525  MOB: 3459  TLI: 65644
sysload=3 (0) cputime=0
scpt: 795324  task: 62(0)  scin: 1805914  scsl: 2923501777  MOB: 3460  TLI: 65643
########################################################
No clock movement in 30 seconds.  Dumping thread status.
*Thread Info*
Semaphore TID: 140556542928640
Scripts Thread Checkpoint: 112
Last Script: pkg/items/doors/door/close_door.ecl PC: 98
Escript Instruction Cycles: 10288143416
Tasks Thread Checkpoint: 1
Active Client Thread Checkpoint: 116
Number of clients: 12
 188.226.30.94 subaru 25
 85.12.211.83 Atabaska 25
 172.21.42.53 debauch1 25
 5.189.45.210 afa 25
 5.189.45.210 presentinho 25
 188.18.114.69 proench 25
 172.21.98.20 eternal 25
 172.21.1.48 bear 25
 92.248.175.246 12345 25
 188.73.187.12 svetlana1 25
 172.21.42.53 debauch 25
 188.226.30.94 Maza_Faka 25
Current Threads:
140554239190784 - SocketClientThread
140554247583488 - SocketClientThread
140554281154304 - SocketClientThread
140554767668992 - SocketClientThread
140554776061696 - SocketClientThread
140554784454400 - SocketClientThread
140554792847104 - SocketClientThread
140554801239808 - SocketClientThread
140554809632512 - SocketClientThread
140554818025216 - SocketClientThread
140555782694656 - SocketClientThread
140555799480064 - SocketClientThread
140555807872768 - Console
140555816265472 - AuxService
140555824658176 - AuxService
140556109846272 - ClientTransmit
140556118238976 - ThreadStatus
140556126631680 - DbgListn
140556135024384 - Reap
140556143417088 - Decay_tokuno
140556151809792 - Decay_malas
140556160202496 - TaskPool http
140556509357824 - Decay_britannia
140556517750528 - Decay_ilshenar
140556526143232 - TaskPool http
140556534535936 - Decay_britannia_alt
140556542928640 - Scripts
140556551321344 - Tasks
140556592498432 - HTTP
140556600891136 - UO Client Listener Port 5003
140557047781376 - Main
Child threads (child_threads): 28
Registered threads (ThreadMap): 31

Nando
POL Developer
Posts: 251
Joined: Wed Sep 17, 2008 6:53 pm
Contact:

Re: "No clock movement" error

Post by Nando » Mon Jul 03, 2017 11:21 am

I got another report of a similar bug, but we could never pinpoint the cause. The user reported to me that the problem went away after they removed a wait_for_event() from inside a critical loop. However, it's not clear if that alone caused the bug.

Could you check if anything weird is happening inside a set_critical?

(By the way, did your other crashes go away? It's already some time...)

Skinny
Journeyman Poster
Posts: 61
Joined: Wed Dec 19, 2012 10:27 pm

Re: "No clock movement" error

Post by Skinny » Mon Jul 03, 2017 11:22 am

Can you show us the code of the file close_door.src?

How is this file is called?
start_script()?
UseScript?
ControlScript?
Do you send events itself or out? Uses set_critical()?

RusseL
Forum Regular
Posts: 333
Joined: Fri Feb 20, 2009 8:30 pm

Re: "No clock movement" error

Post by RusseL » Mon Jul 03, 2017 12:26 pm

Here, really bad code, actually, no idea how case is working here at all (legacy of young-schoolkid-scripterinf from 200x :D)
But it should not hang the server, anyway.

Code: Select all

use cfgfile;
use uo;
use os;
use util;
include "include/client";

program close_door(door)
    if (door.container)
       return;
    endif
    var doordesc := ReadConfigFile("itemdesc");
    var xmod := CInt(doordesc[door.objtype].xmod);
    var ymod := CInt(doordesc[door.objtype].ymod);
    var newx := (door.x - xmod);
    var newy := (door.y - ymod);
    var newz := (door.z);
    var closesound;
    var opensound;
    case (doordesc[door.objtype].doortype)
        default:
         "stone":
                opensound := SFX_OPEN_METAL_DOOR;
                closesound := SFX_CLOSE_METAL_DOOR;
         "wood":
                opensound := SFX_OPEN_WOODEN_DOOR;
                closesound := SFX_CLOSE_WOODEN_DOOR;
         "metal":
                opensound := SFX_OPEN_METAL_DOOR;
                closesound := SFX_CLOSE_METAL_DOOR;
    endcase
    while(1);
      if (!GetObjProperty(door, "WhenOpened"))
           return;
      endif
      if (door.container)
           return;
      endif
      var people := len(ListMobilesNearLocation( newx, newy, newz, 0, door.realm));
      var hidden := len(ListMobilesNearLocationEx( newx, newy, newz, 0, LISTEX_FLAG_HIDDEN, door.realm));
      if((people == 0) and (hidden == 0));
           set_critical(1);
           var movbl := door.movable;
           PlaySoundEffect(door, closesound);
           door.graphic := door.objtype;
           door.movable := 1;
           MoveObjectToLocation (door, newx, newy, newz, door.realm, MOVEOBJECT_FORCELOCATION);
           door.movable := movbl;
           EraseObjProperty(door, "WhenOpened");
           return;
      endif
      sleep(1);
    endwhile
endprogram
and listing: pkg/items/doors/door/close_door.ecl PC: 98

Code: Select all

91: get member id 'container' (15)
92: if false goto 95
return;
93: ""
94: progend
var people := len(ListMobilesNearLocation( newx, newy, newz, 0, door.realm));
95: decl local #0
96: local #4
97: local #5
98: local #6
99: 0L
100: local #0
101: get member id 'realm' (112)
102: Func(3,1): ListMobilesNearLocation
103: Func(0,1): Len
104: :=
105: #
var hidden := len(ListMobilesNearLocationEx( newx, newy, newz, 0, LISTEX_FLAG_H

Skinny
Journeyman Poster
Posts: 61
Joined: Wed Dec 19, 2012 10:27 pm

Re: "No clock movement" error

Post by Skinny » Mon Jul 03, 2017 2:05 pm

How is this file is called?

RusseL
Forum Regular
Posts: 333
Joined: Fri Feb 20, 2009 8:30 pm

Re: "No clock movement" error

Post by RusseL » Mon Jul 03, 2017 2:16 pm

Skinny wrote:
Mon Jul 03, 2017 2:05 pm
How is this file is called?
from door use script

ugghh sleep inside of critical part :D

Code: Select all

...............

    set_critical(1);
    var movbl := door.movable;
    PlaySoundEffect( door, opensound );
    door.graphic := opengraphic;
    door.movable := 1;
    MoveObjectToLocation (door, newx, newy, newz, door.realm, MOVEOBJECT_FORCELOCATION);
    door.movable := movbl;
    SetObjProperty( door, "WhenOpened", whenopened );

    sleep( 10 );
    if (GetObjProperty( door, "WhenOpened" ))
        start_script(":doors:door/close_door", door);
    endif

    set_critical(0);
    
  ............

Nando
POL Developer
Posts: 251
Joined: Wed Sep 17, 2008 6:53 pm
Contact:

Re: "No clock movement" error

Post by Nando » Mon Jul 03, 2017 2:30 pm

What's your ReportCriticalScripts in pol.cfg?

Skinny
Journeyman Poster
Posts: 61
Joined: Wed Dec 19, 2012 10:27 pm

Re: "No clock movement" error

Post by Skinny » Mon Jul 03, 2017 2:50 pm

http://docs.polserver.com/pol099/script ... #UseScript
Scheduler Type
Normal
Default Priority
100
Try to move "sleep(10);" to close_door.src script, in first line.
Remove Sleep() on critical part.

I think this script caller doesn't need use set_critical.

Before, try to reproduce this bug:
~20 players or more opening and closing doors many, many, many times for second with macro.

RusseL
Forum Regular
Posts: 333
Joined: Fri Feb 20, 2009 8:30 pm

Re: "No clock movement" error

Post by RusseL » Mon Jul 03, 2017 3:05 pm

Skinny wrote:
Mon Jul 03, 2017 2:50 pm
Try to move "sleep(10);" to close_door.src script, in first line.
Remove Sleep() on critical part.
I think this script caller doesn't need use set_critical.
sure, i already completely reworked both scripts, after seen whats goin on there... Never touched it before, as it is working over 10 years so :D
Skinny wrote:
Mon Jul 03, 2017 2:50 pm
Before, try to reproduce this bug:
~20 players or more opening and closing doors many, many, many times for second with macro.
meeeeeh... so wait till Autumn, then i get 20+ players on my shard :) Everything is dead, summer...
So, i dont think that there were more than 1 player pressing 'Close Door' at the same time
Nando wrote:
Mon Jul 03, 2017 2:30 pm
What's your ReportCriticalScripts in pol.cfg?
ReportCriticalScripts=0

Nando
POL Developer
Posts: 251
Joined: Wed Sep 17, 2008 6:53 pm
Contact:

Re: "No clock movement" error

Post by Nando » Mon Jul 03, 2017 10:29 pm

Change it to 1. It will report when a critical script runs for more than 1000 instructions.

Nando
POL Developer
Posts: 251
Joined: Wed Sep 17, 2008 6:53 pm
Contact:

Re: "No clock movement" error

Post by Nando » Wed Jul 12, 2017 10:25 pm

Did it help? It would be good to know whether bugs are fixed... :)

RusseL
Forum Regular
Posts: 333
Joined: Fri Feb 20, 2009 8:30 pm

Re: "No clock movement" error

Post by RusseL » Thu Jul 13, 2017 2:34 am

hey Nando,

this bug appeared very rarely, twice in a last 2 years, so i can't say now if it helped. Actually, i just wanted to ask how to debug such things generally :)
And now i reworked my open_door close_door scripts completely, so, i think it shouldnt hang anymore.

Sure, i will report if it will hang again :)
Thank you

Nando
POL Developer
Posts: 251
Joined: Wed Sep 17, 2008 6:53 pm
Contact:

Re: "No clock movement" error

Post by Nando » Thu Jul 13, 2017 2:44 am

I'm also at a loss with this bug, that's why I'm looking for any information on it. Skinny has reported it to me many times for a few years now. Apparently it went away after he fixed some critical scripts.

My hypothesis is a problem in the scheduler. It seems that within some special condition, the script thread gets stuck in an infinite loop in the scheduler, running the same scripts over and over and never releasing the global lock (sort of a livelock). It could be related to a race condition, but I could never reproduce it.

It would be helpful if someone could reproduce it.

Post Reply

Who is online

Users browsing this forum: No registered users and 1 guest