--- deliantra/server/lib/cf.pm	2010/04/16 02:21:26	1.518
+++ deliantra/server/lib/cf.pm	2010/05/06 22:57:49	1.546
@@ -22,9 +22,7 @@
 
 package cf;
 
-use 5.10.0;
-use utf8;
-use strict qw(vars subs);
+use common::sense;
 
 use Symbol;
 use List::Util;
@@ -80,6 +78,8 @@
 
 sub WF_AUTOCANCEL () { 1 } # automatically cancel this watcher on reload
 
+our @ORIG_INC;
+
 our %COMMAND      = ();
 our %COMMAND_TIME = ();
 
@@ -108,10 +108,13 @@
 our $PIDFILE     = "$LOCALDIR/pid";
 our $RUNTIMEFILE = "$LOCALDIR/runtime";
 
-our %RESOURCE;
+our %RESOURCE; # unused
+
+our $OUTPUT_RATE_MIN =    3000;
+our $OUTPUT_RATE_MAX = 1000000;
 
-our $OUTPUT_RATE_MIN =   4000;
-our $OUTPUT_RATE_MAX = 100000;
+our $MAX_LINKS       = 32; # how many chained exits to follow
+our $VERBOSE_IO      = 1;
 
 our $TICK = MAX_TIME * 1e-6; # this is a CONSTANT(!)
 our $NEXT_RUNTIME_WRITE; # when should the runtime file be written
@@ -123,7 +126,7 @@
 our $BDB_TRICKLE_WATCHER;
 our $DB_ENV;
 
-our @EXTRA_MODULES = qw(pod match mapscript);
+our @EXTRA_MODULES = qw(pod match mapscript incloader);
 
 our %CFG;
 
@@ -167,6 +170,10 @@
 
 sub cf::map::normalise;
 
+sub in_main() {
+   $Coro::current == $Coro::main
+}
+
 #############################################################################
 
 %REFLECT = ();
@@ -228,9 +235,14 @@
 =item cf::wait_for_tick, cf::wait_for_tick_begin
 
 These are functions that inhibit the current coroutine one tick. cf::wait_for_tick_begin only
-returns directly I<after> the tick processing (and consequently, can only wake one process
+returns directly I<after> the tick processing (and consequently, can only wake one thread
 per tick), while cf::wait_for_tick wakes up all waiters after tick processing.
 
+=cut
+
+sub wait_for_tick();
+sub wait_for_tick_begin();
+
 =item @cf::INVOKE_RESULTS
 
 This array contains the results of the last C<invoke ()> call. When
@@ -247,6 +259,12 @@
 
 =cut
 
+sub error(@) { LOG llevError, join "", @_ }
+sub warn (@) { LOG llevWarn , join "", @_ }
+sub info (@) { LOG llevInfo , join "", @_ }
+sub debug(@) { LOG llevDebug, join "", @_ }
+sub trace(@) { LOG llevTrace, join "", @_ }
+
 $Coro::State::WARNHOOK = sub {
    my $msg = join "", @_;
 
@@ -255,16 +273,16 @@
 
    $msg =~ s/([\x00-\x08\x0b-\x1f])/sprintf "\\x%02x", ord $1/ge;
 
-   LOG llevError, $msg;
+   LOG llevWarn, $msg;
 };
 
 $Coro::State::DIEHOOK = sub {
    return unless $^S eq 0; # "eq", not "=="
 
-   warn Carp::longmess $_[0];
+   error Carp::longmess $_[0];
 
-   if ($Coro::current == $Coro::main) {#d#
-      warn "DIEHOOK called in main context, Coro bug?\n";#d#
+   if (in_main) {#d#
+      error "DIEHOOK called in main context, Coro bug?\n";#d#
       return;#d#
    }#d#
 
@@ -507,13 +525,13 @@
 sub sync_job(&) {
    my ($job) = @_;
 
-   if ($Coro::current == $Coro::main) {
+   if (in_main) {
       my $time = AE::time;
 
       # this is the main coro, too bad, we have to block
       # till the operation succeeds, freezing the server :/
       
-      LOG llevError, Carp::longmess "sync job";#d#
+      #LOG llevError, Carp::longmess "sync job";#d#
 
       my $freeze_guard = freeze_mainloop;
 
@@ -523,7 +541,7 @@
       (async {
          $Coro::current->desc ("sync job coro");
          @res = eval { $job->() };
-         warn $@ if $@;
+         error $@ if $@;
          undef $busy;
       })->prio (Coro::PRIO_MAX);
 
@@ -646,6 +664,9 @@
 =cut
 
 sub db_table($) {
+   cf::error "db_get called from main context"
+      if $Coro::current == $Coro::main;
+
    my ($name) = @_;
    my $db = BDB::db_create $DB_ENV;
 
@@ -665,20 +686,19 @@
 our $DB;
 
 sub db_init {
-   cf::sync_job {
-      $DB ||= db_table "db";
-   };
+   $DB ||= db_table "db";
 }
 
 sub db_get($$) {
    my $key = "$_[0]/$_[1]";
 
-   cf::sync_job {
-      BDB::db_get $DB, undef, $key, my $data;
+   cf::error "db_get called from main context"
+      if $Coro::current == $Coro::main;
 
-      $! ? ()
-         : $data
-   }
+   BDB::db_get $DB, undef, $key, my $data;
+
+   $! ? ()
+      : $data
 }
 
 sub db_put($$$) {
@@ -744,7 +764,7 @@
       my $data = $process->(\@data);
       my $t2 = Time::HiRes::time;
 
-      warn "cache: '$id' processed in ", $t2 - $t1, "s\n";
+      info "cache: '$id' processed in ", $t2 - $t1, "s\n";
 
       db_put cache => "$id/data", $data;
       db_put cache => "$id/md5" , $md5;
@@ -764,7 +784,7 @@
 
 sub datalog($@) {
   my ($type, %kv) = @_;
-  warn "DATALOG ", JSON::XS->new->ascii->encode ({ %kv, type => $type });
+  info "DATALOG ", JSON::XS->new->ascii->encode ({ %kv, type => $type });
 }
 
 =back
@@ -969,11 +989,11 @@
          _attach_cb $registry, $cb_id{$type}, $prio, shift @arg;
 
       } elsif (ref $type) {
-         warn "attaching objects not supported, ignoring.\n";
+         error "attaching objects not supported, ignoring.\n";
 
       } else {
          shift @arg;
-         warn "attach argument '$type' not supported, ignoring.\n";
+         error "attach argument '$type' not supported, ignoring.\n";
       }
    }
 }
@@ -993,7 +1013,7 @@
 
       $obj->{$name} = \%arg;
    } else {
-      warn "object uses attachment '$name' which is not available, postponing.\n";
+      info "object uses attachment '$name' which is not available, postponing.\n";
    }
 
    $obj->{_attachment}{$name} = undef;
@@ -1062,8 +1082,7 @@
       eval { &{$_->[1]} };
 
       if ($@) {
-         warn "$@";
-         warn "... while processing $EVENT[$event][0](@_) event, skipping processing altogether.\n";
+         error "$@", "... while processing $EVENT[$event][0](@_) event, skipping processing altogether.\n";
          override;
       }
 
@@ -1152,7 +1171,7 @@
             _attach $registry, $klass, @attach;
          }
       } else {
-         warn "object uses attachment '$name' that is not available, postponing.\n";
+         info "object uses attachment '$name' that is not available, postponing.\n";
       }
    }
 }
@@ -1189,8 +1208,9 @@
    sync_job {
       if (length $$rdata) {
          utf8::decode (my $decname = $filename);
-         warn sprintf "saving %s (%d,%d)\n",
-            $decname, length $$rdata, scalar @$objs;
+         trace sprintf "saving %s (%d,%d)\n",
+                       $decname, length $$rdata, scalar @$objs
+            if $VERBOSE_IO;
 
          if (my $fh = aio_open "$filename~", O_WRONLY | O_CREAT, 0600) {
             aio_chmod $fh, SAVE_MODE;
@@ -1222,7 +1242,7 @@
             $filename =~ s%/[^/]+$%%;
             aio_pathsync $filename if $cf::USE_FSYNC;
          } else {
-            warn "unable to save objects: $filename~: $!\n";
+            error "unable to save objects: $filename~: $!\n";
          }
       } else {
          aio_unlink $filename;
@@ -1256,8 +1276,9 @@
    }
 
    utf8::decode (my $decname = $filename);
-   warn sprintf "loading %s (%d,%d)\n",
-      $decname, length $data, scalar @{$av || []};
+   trace sprintf "loading %s (%d,%d)\n",
+                 $decname, length $data, scalar @{$av || []}
+      if $VERBOSE_IO;
 
    ($data, $av)
 }
@@ -1359,7 +1380,7 @@
             if $reply;
 
       } else {
-         warn "player " . ($pl->ob->name) . " sent unparseable ext message: <$buf>\n";
+         error "player " . ($pl->ob->name) . " sent unparseable ext message: <$buf>\n";
       }
 
       cf::override;
@@ -1380,6 +1401,8 @@
 }
 
 sub load_extensions {
+   info "loading extensions...";
+
    cf::sync_job {
       my %todo;
 
@@ -1407,7 +1430,7 @@
             if $source =~ /\A#!.*?perl.*?#\s*(.*)$/m;
 
          $ext{source} =
-            "package $pkg; use 5.10.0; use strict 'vars', 'subs'; use utf8;\n"
+            "package $pkg; use common::sense;\n"
             . "#line 1 \"$path\"\n{\n"
             . $source
             . "\n};\n1";
@@ -1429,21 +1452,24 @@
                   unless exists $done{$_};
             }
 
-            warn "... pass $pass, loading '$k' into '$v->{pkg}'\n";
+            trace "... pass $pass, loading '$k' into '$v->{pkg}'\n";
 
             my $active = eval $v->{source};
 
             if (length $@) {
-               warn "$v->{path}: $@\n";
+               error "$v->{path}: $@\n";
 
                cf::cleanup "mandatory extension '$k' failed to load, exiting."
                   if exists $v->{meta}{mandatory};
+
+               warn "$v->{base}: optional extension cannot be loaded, skipping.\n";
+               delete $todo{$k};
             } else {
                $done{$k} = delete $todo{$k};
                push @EXTS, $v->{pkg};
                $progress = 1;
 
-               warn "$v->{base}: extension inactive.\n"
+               info "$v->{base}: extension inactive.\n"
                   unless $active;
             }
          }
@@ -1625,7 +1651,6 @@
    $pl->invoke (cf::EVENT_PLAYER_LOGOUT, 1) if $pl->active;
    $pl->deactivate;
    my $killer = cf::arch::get "killer_quit"; $pl->killer ($killer); $killer->destroy;
-   $pl->ob->check_score;
    $pl->invoke (cf::EVENT_PLAYER_QUIT);
    $pl->ns->destroy if $pl->ns;
 
@@ -1690,6 +1715,8 @@
 
 =item $player->maps
 
+=item cf::player::maps $login
+
 Returns an arrayref of map paths that are private for this
 player. May block.
 
@@ -1761,6 +1788,8 @@
 sub find_by_path($) {
    my ($path) = @_;
 
+   $path =~ s/^~[^\/]*//; # skip ~login
+
    my ($match, $specificity);
 
    for my $region (list) {
@@ -1826,14 +1855,13 @@
    my (undef, $regex, $prio) = @_;
    my $pkg = caller;
 
-   no strict;
    push @{"$pkg\::ISA"}, __PACKAGE__;
 
    $EXT_MAP{$pkg} = [$prio, qr<$regex>];
 }
 
 # also paths starting with '/'
-$EXT_MAP{"cf::map"} = [0, qr{^(?=/)}];
+$EXT_MAP{"cf::map::wrap"} = [0, qr{^(?=/)}];
 
 sub thawer_merge {
    my ($self, $merge) = @_;
@@ -1848,7 +1876,7 @@
 sub normalise {
    my ($path, $base) = @_;
 
-   $path = "$path"; # make sure its a string
+   $path = "$path"; # make sure it's a string
 
    $path =~ s/\.map$//;
 
@@ -1897,7 +1925,7 @@
       }
    }
 
-   Carp::cluck "unable to resolve path '$path' (base '$base').";
+   Carp::cluck "unable to resolve path '$path' (base '$base')";
    ()
 }
 
@@ -2030,6 +2058,8 @@
 sub find {
    my ($path, $origin) = @_;
 
+   cf::cede_to_tick;
+
    $path = normalise $path, $origin && $origin->path;
 
    my $guard1 = cf::lock_acquire "map_data:$path";#d#remove
@@ -2153,6 +2183,7 @@
          or next;
       $neigh->load;
 
+      # now find the diagonal neighbours
       push @neigh,
          [$neigh->tile_path (($_ + 3) % 4), $neigh],
          [$neigh->tile_path (($_ + 1) % 4), $neigh];
@@ -2169,16 +2200,19 @@
 sub find_sync {
    my ($path, $origin) = @_;
 
-   cf::sync_job { find $path, $origin }
+   return cf::LOG cf::llevError | cf::logBacktrace, "do_find_sync"
+      if $Coro::current == $Coro::main;
+
+   find $path, $origin
 }
 
 sub do_load_sync {
    my ($map) = @_;
 
-   cf::LOG cf::llevDebug | cf::logBacktrace, "do_load_sync"
+   return cf::LOG cf::llevError | cf::logBacktrace, "do_load_sync"
       if $Coro::current == $Coro::main;
 
-   cf::sync_job { $map->load };
+   $map->load;
 }
 
 our %MAP_PREFETCH;
@@ -2300,7 +2334,7 @@
 
    return if $self->players;
 
-   warn "resetting map ", $self->path, "\n";
+   cf::trace "resetting map ", $self->path, "\n";
 
    $self->in_memory (cf::MAP_SWAPPED);
 
@@ -2334,7 +2368,7 @@
 
       $self->unlink_save;
 
-      bless $self, "cf::map";
+      bless $self, "cf::map::wrap";
       delete $self->{deny_reset};
       $self->{deny_save} = 1;
       $self->reset_timeout (1);
@@ -2574,7 +2608,7 @@
 
 The player should be reasonably safe there for short amounts of time (e.g.
 for loading a map). You I<MUST> call C<leave_link> as soon as possible,
-though, as the palyer cannot control the character while it is on the link
+though, as the player cannot control the character while it is on the link
 map.
 
 Will never block.
@@ -2605,12 +2639,14 @@
 
    $self->deactivate_recursive;
 
+   ++$self->{_link_recursion};
+
    return if UNIVERSAL::isa $self->map, "ext::map_link";
 
    $self->{_link_pos} ||= [$self->map->{path}, $self->x, $self->y]
       if $self->map && $self->map->{path} ne "{link}";
 
-   $self->enter_map ($LINK_MAP || link_map, 10, 10);
+   $self->enter_map ($LINK_MAP || link_map, 3, 3);
 }
 
 sub cf::object::player::leave_link {
@@ -2645,13 +2681,16 @@
    return unless $self->contr->active;
 
    local $self->{_prev_pos} = $link_pos; # ugly hack for rent.ext
-   $self->enter_map ($map, $x, $y);
+   if ($self->enter_map ($map, $x, $y)) {
+      # entering was successful
+      delete $self->{_link_recursion};
+      # only activate afterwards, to support waiting in hooks
+      $self->activate_recursive;
+   }
 
-   # only activate afterwards, to support waiting in hooks
-   $self->activate_recursive;
 }
 
-=item $player_object->goto ($path, $x, $y[, $check->($map)[, $done->()]])
+=item $player_object->goto ($path, $x, $y[, $check->($map, $x, $y, $player)[, $done->($player)]])
 
 Moves the player to the given map-path and coordinates by first freezing
 her, loading and preparing them map, calling the provided $check callback
@@ -2669,6 +2708,12 @@
 sub cf::object::player::goto {
    my ($self, $path, $x, $y, $check, $done) = @_;
 
+   if ($self->{_link_recursion} >= $MAX_LINKS) {
+      error "FATAL: link recursion exceeded, ", $self->name, " goto $path $x $y, redirecting.";
+      $self->failmsg ("Something went wrong inside the server - please contact an administrator!");
+      ($path, $x, $y) = @$EMERGENCY_POSITION;
+   }
+
    # do generation counting so two concurrent goto's will be executed in-order
    my $gen = $self->{_goto_generation} = ++$GOTOGEN;
 
@@ -2701,7 +2746,7 @@
 
          if ($map) {
             $map = $map->customise_for ($self);
-            $map = $check->($map) if $check && $map;
+            $map = $check->($map, $x, $y, $self) if $check && $map;
          } else {
             $self->message ("The exit to '$path' is closed.", cf::NDI_UNIQUE | cf::NDI_RED);
          }
@@ -2719,7 +2764,7 @@
          $self->leave_link ($map, $x, $y);
       }
 
-      $done->() if $done;
+      $done->($self) if $done;
    })->prio (1);
 }
 
@@ -2822,7 +2867,7 @@
                        . "Please report this to the dungeon master!",
                          cf::NDI_UNIQUE | cf::NDI_RED);
 
-         warn "ERROR in enter_exit: $@";
+         error "ERROR in enter_exit: $@";
          $self->leave_link;
       }
    })->prio (1);
@@ -3145,7 +3190,7 @@
             if $reply;
 
       } else {
-         warn "client " . ($ns->pl ? $ns->pl->ob->name : $ns->host) . " sent unparseable exti message: <$buf>\n";
+         error "client " . ($ns->pl ? $ns->pl->ob->name : $ns->host) . " sent unparseable exti message: <$buf>\n";
       }
 
       cf::override;
@@ -3236,7 +3281,6 @@
    ["cf::player"         => qw(peaceful send_msg)],
    ["cf::map"            => qw(trigger)],
 ) {
-   no strict 'refs';
    my ($pkg, @funs) = @$_;
    *{"safe::$pkg\::$_"} = $safe_hole->wrap (\&{"$pkg\::$_"})
       for @funs;
@@ -3285,9 +3329,9 @@
    }
 
    if ($@) {
-      warn "$@";
-      warn "while executing safe code '$code'\n";
-      warn "with arguments " . (join " ", %vars) . "\n";
+      warn "$@",
+           "while executing safe code '$code'\n",
+           "with arguments " . (join " ", %vars) . "\n";
    }
 
    wantarray ? @res : $res[0]
@@ -3331,10 +3375,9 @@
 
    my $enc = JSON::XS->new->utf8->canonical->relaxed;
 
-   warn "loading facedata from $path\n";
+   trace "loading facedata from $path\n";
 
-   my $facedata;
-   0 < aio_load $path, $facedata
+   0 < aio_load $path, my $facedata
       or die "$path: $!";
 
    $facedata = Coro::Storable::thaw $facedata;
@@ -3375,7 +3418,7 @@
             cf::face::set_smooth      $idx, $smooth;
             cf::face::set_smoothlevel $idx, $info->{smoothlevel};
          } else {
-            warn "smooth face '$info->{smooth}' not found for face '$face'";
+            error "smooth face '$info->{smooth}' not found for face '$face'";
          }
 
          cf::cede_to_tick;
@@ -3403,7 +3446,7 @@
             cf::face::set_data $idx, 0, $info->{data}, $info->{hash};
             cf::face::set_type $idx, $info->{type};
          } else {
-            $RESOURCE{$name} = $info;
+            $RESOURCE{$name} = $info; # unused
          }
 
          cf::cede_to_tick;
@@ -3415,26 +3458,6 @@
    1
 }
 
-cf::global->attach (on_resource_update => sub {
-   if (my $soundconf = $RESOURCE{"res/sound.conf"}) {
-      $soundconf = JSON::XS->new->utf8->relaxed->decode ($soundconf->{data});
-
-      for (0 .. SOUND_CAST_SPELL_0 - 1) {
-         my $sound = $soundconf->{compat}[$_]
-            or next;
-
-         my $face = cf::face::find "sound/$sound->[1]";
-         cf::sound::set $sound->[0] => $face;
-         cf::sound::old_sound_index $_, $face; # gcfclient-compat
-      }
-
-      while (my ($k, $v) = each %{$soundconf->{event}}) {
-         my $face = cf::face::find "sound/$v";
-         cf::sound::set $k => $face;
-      }
-   }
-});
-
 register_exticmd fx_want => sub {
    my ($ns, $want) = @_;
 
@@ -3482,27 +3505,55 @@
       or die "unable to load treasurelists\n";
 }
 
+sub reload_sound {
+   trace "loading sound config from $DATADIR/sound\n";
+
+   0 < Coro::AIO::aio_load "$DATADIR/sound", my $data
+      or die "$DATADIR/sound $!";
+
+   my $soundconf = JSON::XS->new->utf8->relaxed->decode ($data);
+
+   for (0 .. SOUND_CAST_SPELL_0 - 1) {
+      my $sound = $soundconf->{compat}[$_]
+         or next;
+
+      my $face = cf::face::find "sound/$sound->[1]";
+      cf::sound::set $sound->[0] => $face;
+      cf::sound::old_sound_index $_, $face; # gcfclient-compat
+   }
+
+   while (my ($k, $v) = each %{$soundconf->{event}}) {
+      my $face = cf::face::find "sound/$v";
+      cf::sound::set $k => $face;
+   }
+}
+
 sub reload_resources {
-   warn "reloading resource files...\n";
+   trace "reloading resource files...\n";
 
+   reload_exp_table;
+   reload_materials;
    reload_facedata;
+   reload_sound;
    reload_archetypes;
    reload_regions;
    reload_treasures;
 
-   warn "finished reloading resource files\n";
+   trace "finished reloading resource files\n";
 }
 
 sub reload_config {
-   warn "reloading config file...\n";
+   trace "reloading config file...\n";
 
-   open my $fh, "<:utf8", "$CONFDIR/config"
-      or return;
+   0 < aio_load "$CONFDIR/config", my $config
+      or die "$CONFDIR/config: $!";
 
-   local $/;
-   *CFG = YAML::XS::Load scalar <$fh>;
+   utf8::decode $config;
 
-   $EMERGENCY_POSITION = $CFG{emergency_position} || ["/world/world_105_115", 5, 37];
+   cf::get_slot 0.1, 10, "reload_config"; # yaml might be slow...
+   *CFG = YAML::XS::Load $config;
+
+   $EMERGENCY_POSITION = $CFG{emergency_position} || ["/world/world_104_115", 49, 38];
 
    $cf::map::MAX_RESET     = $CFG{map_max_reset}     if exists $CFG{map_max_reset};
    $cf::map::DEFAULT_RESET = $CFG{map_default_reset} if exists $CFG{map_default_reset};
@@ -3514,8 +3565,6 @@
       };
       warn $@ if $@;
    }
-
-   warn "finished reloading resource files\n";
 }
 
 sub pidfile() {
@@ -3538,11 +3587,11 @@
 }
 
 sub main_loop {
-   warn "EV::loop starting\n";
+   trace "EV::loop starting\n";
    if (1) {
       EV::loop;
    }
-   warn "EV::loop returned\n";
+   trace "EV::loop returned\n";
    goto &main_loop unless $REALLY_UNLOOP;
 }
 
@@ -3550,7 +3599,7 @@
    cf::init_globals; # initialise logging
 
    LOG llevInfo, "Welcome to Deliantra, v" . VERSION;
-   LOG llevInfo, "Copyright (C) 2005-2008 Marc Alexander Lehmann / Robin Redeker / the Deliantra team.";
+   LOG llevInfo, "Copyright (C) 2005-2010 Marc Alexander Lehmann / Robin Redeker / the Deliantra team.";
    LOG llevInfo, "Copyright (C) 1994 Mark Wedel.";
    LOG llevInfo, "Copyright (C) 1992 Frank Tore Johansen.";
 
@@ -3568,13 +3617,13 @@
    evthread_start IO::AIO::poll_fileno;
 
    cf::sync_job {
-      cf::init_experience;
+      cf::incloader::init ();
+
       cf::init_anim;
       cf::init_attackmess;
       cf::init_dynamic;
 
       cf::load_settings;
-      cf::load_materials;
 
       reload_resources;
       reload_config;
@@ -3600,9 +3649,14 @@
    };
 
    cf::object::thawer::errors_are_fatal 0;
-   warn "parse errors in files are no longer fatal from this point on.\n";
+   info "parse errors in files are no longer fatal from this point on.\n";
+
+   my $free_main; $free_main = EV::idle sub {
+      undef $free_main;
+      undef &main; # free gobs of memory :)
+   };
 
-   main_loop;
+   goto &main_loop;
 }
 
 #############################################################################
@@ -3651,7 +3705,7 @@
    aio_rename "$RUNTIMEFILE~", $RUNTIMEFILE
       and return;
 
-   warn sprintf "runtime file written (%gs).\n", AE::time - $t0;
+   trace sprintf "runtime file written (%gs).\n", AE::time - $t0;
 
    1
 }
@@ -3673,7 +3727,7 @@
    my $value = uuid_seq uuid_cur;
 
    unless ($value) {
-      warn "cowardly refusing to write zero uuid value!\n";
+      info "cowardly refusing to write zero uuid value!\n";
       return;
    }
 
@@ -3693,7 +3747,7 @@
    aio_rename "$uuid~", $uuid
       and return;
 
-   warn "uuid file written ($value).\n";
+   trace "uuid file written ($value).\n";
 
    1
 
@@ -3709,55 +3763,77 @@
 sub emergency_save() {
    my $freeze_guard = cf::freeze_mainloop;
 
-   warn "emergency_perl_save: enter\n";
+   info "emergency_perl_save: enter\n";
+
+   # this is a trade-off: we want to be very quick here, so
+   # save all maps without fsync, and later call a global sync
+   # (which in turn might be very very slow)
+   local $USE_FSYNC = 0;
 
    cf::sync_job {
-      # this is a trade-off: we want to be very quick here, so
-      # save all maps without fsync, and later call a global sync
-      # (which in turn might be very very slow)
-      local $USE_FSYNC = 0;
+      cf::write_runtime_sync; # external watchdog should not bark
 
       # use a peculiar iteration method to avoid tripping on perl
       # refcount bugs in for. also avoids problems with players
       # and maps saved/destroyed asynchronously.
-      warn "emergency_perl_save: begin player save\n";
+      info "emergency_perl_save: begin player save\n";
       for my $login (keys %cf::PLAYER) {
          my $pl = $cf::PLAYER{$login} or next;
          $pl->valid or next;
          delete $pl->{unclean_save}; # not strictly necessary, but cannot hurt
          $pl->save;
       }
-      warn "emergency_perl_save: end player save\n";
+      info "emergency_perl_save: end player save\n";
 
-      warn "emergency_perl_save: begin map save\n";
+      cf::write_runtime_sync; # external watchdog should not bark
+
+      info "emergency_perl_save: begin map save\n";
       for my $path (keys %cf::MAP) {
          my $map = $cf::MAP{$path} or next;
          $map->valid or next;
          $map->save;
       }
-      warn "emergency_perl_save: end map save\n";
+      info "emergency_perl_save: end map save\n";
+
+      cf::write_runtime_sync; # external watchdog should not bark
 
-      warn "emergency_perl_save: begin database checkpoint\n";
+      info "emergency_perl_save: begin database checkpoint\n";
       BDB::db_env_txn_checkpoint $DB_ENV;
-      warn "emergency_perl_save: end database checkpoint\n";
+      info "emergency_perl_save: end database checkpoint\n";
 
-      warn "emergency_perl_save: begin write uuid\n";
+      info "emergency_perl_save: begin write uuid\n";
       write_uuid_sync 1;
-      warn "emergency_perl_save: end write uuid\n";
-   };
+      info "emergency_perl_save: end write uuid\n";
+
+      cf::write_runtime_sync; # external watchdog should not bark
+
+      trace "emergency_perl_save: syncing database to disk";
+      BDB::db_env_txn_checkpoint $DB_ENV;
+
+      info "emergency_perl_save: starting sync\n";
+      IO::AIO::aio_sync sub {
+         info "emergency_perl_save: finished sync\n";
+      };
+
+      cf::write_runtime_sync; # external watchdog should not bark
 
-   warn "emergency_perl_save: starting sync()\n";
-   IO::AIO::aio_sync sub {
-      warn "emergency_perl_save: finished sync()\n";
+      trace "emergency_perl_save: flushing outstanding aio requests";
+      while (IO::AIO::nreqs || BDB::nreqs) {
+         Coro::EV::timer_once 0.01; # let the sync_job do it's thing
+      }
+
+      cf::write_runtime_sync; # external watchdog should not bark
    };
 
-   warn "emergency_perl_save: leave\n";
+   info "emergency_perl_save: leave\n";
 }
 
 sub post_cleanup {
    my ($make_core) = @_;
 
-   warn Carp::longmess "post_cleanup backtrace"
+   IO::AIO::flush;
+
+   error Carp::longmess "post_cleanup backtrace"
       if $make_core;
 
    my $fh = pidfile;
@@ -3787,13 +3863,12 @@
       _gv_clear *{"$pkg$name"};
 #      use PApp::Util; PApp::Util::sv_dump *{"$pkg$name"};
    }
-   warn "cleared package $pkg\n";#d#
 }
 
 sub do_reload_perl() {
    # can/must only be called in main
-   if ($Coro::current != $Coro::main) {
-      warn "can only reload from main coroutine";
+   unless (in_main) {
+      error "can only reload from main coroutine";
       return;
    }
 
@@ -3802,56 +3877,45 @@
    my $t1 = AE::time;
 
    while ($RELOAD) {
-      warn "reloading...";
+      cf::get_slot 0.1, -1, "reload_perl";
+      info "reloading...";
 
-      warn "entering sync_job";
+      trace "entering sync_job";
 
       cf::sync_job {
-         cf::write_runtime_sync; # external watchdog should not bark
-         cf::emergency_save;
-         cf::write_runtime_sync; # external watchdog should not bark
-
-         warn "syncing database to disk";
-         BDB::db_env_txn_checkpoint $DB_ENV;
+         #cf::emergency_save;
 
-         # if anything goes wrong in here, we should simply crash as we already saved
-
-         warn "flushing outstanding aio requests";
-         while (IO::AIO::nreqs || BDB::nreqs) {
-            Coro::EV::timer_once 0.01; # let the sync_job do it's thing
-         }
-
-         warn "cancelling all extension coros";
+         trace "cancelling all extension coros";
          $_->cancel for values %EXT_CORO;
          %EXT_CORO = ();
 
-         warn "removing commands";
+         trace "removing commands";
          %COMMAND = ();
 
-         warn "removing ext/exti commands";
+         trace "removing ext/exti commands";
          %EXTCMD  = ();
          %EXTICMD = ();
 
-         warn "unloading/nuking all extensions";
+         trace "unloading/nuking all extensions";
          for my $pkg (@EXTS) {
-            warn "... unloading $pkg";
+            trace "... unloading $pkg";
 
             if (my $cb = $pkg->can ("unload")) {
                eval {
                   $cb->($pkg);
                   1
-               } or warn "$pkg unloaded, but with errors: $@";
+               } or error "$pkg unloaded, but with errors: $@";
             }
 
-            warn "... clearing $pkg";
+            trace "... clearing $pkg";
             clear_package $pkg;
          }
 
-         warn "unloading all perl modules loaded from $LIBDIR";
+         trace "unloading all perl modules loaded from $LIBDIR";
          while (my ($k, $v) = each %INC) {
             next unless $v =~ /^\Q$LIBDIR\E\/.*\.pm$/;
 
-            warn "... unloading $k";
+            trace "... unloading $k";
             delete $INC{$k};
 
             $k =~ s/\.pm$//;
@@ -3864,11 +3928,11 @@
             clear_package $k;
          }
 
-         warn "getting rid of safe::, as good as possible";
+         trace "getting rid of safe::, as good as possible";
          clear_package "safe::$_"
             for qw(cf::attachable cf::object cf::object::player cf::client cf::player cf::map cf::party cf::region);
 
-         warn "unloading cf.pm \"a bit\"";
+         trace "unloading cf.pm \"a bit\"";
          delete $INC{"cf.pm"};
          delete $INC{"cf/$_.pm"} for @EXTRA_MODULES;
 
@@ -3876,44 +3940,44 @@
          # and global variables created in xs
          #clear_package __PACKAGE__;
 
-         warn "unload completed, starting to reload now";
+         info "unload completed, starting to reload now";
 
-         warn "reloading cf.pm";
+         trace "reloading cf.pm";
          require cf;
          cf::_connect_to_perl_1;
 
-         warn "loading config and database again";
+         trace "loading config and database again";
          cf::reload_config;
 
-         warn "loading extensions";
+         trace "loading extensions";
          cf::load_extensions;
 
          if ($REATTACH_ON_RELOAD) {
-            warn "reattaching attachments to objects/players";
+            trace "reattaching attachments to objects/players";
             _global_reattach; # objects, sockets
-            warn "reattaching attachments to maps";
+            trace "reattaching attachments to maps";
             reattach $_ for values %MAP;
-            warn "reattaching attachments to players";
+            trace "reattaching attachments to players";
             reattach $_ for values %PLAYER;
          }
 
-         warn "running post_init jobs";
+         trace "running post_init jobs";
          (pop @POST_INIT)->(1) while @POST_INIT;
 
-         warn "leaving sync_job";
+         trace "leaving sync_job";
 
          1
       } or do {
-         warn $@;
+         error $@;
          cf::cleanup "error while reloading, exiting.";
       };
 
-      warn "reloaded";
+      info "reloaded";
       --$RELOAD;
    }
 
    $t1 = AE::time - $t1;
-   warn "reload completed in ${t1}s\n";
+   info "reload completed in ${t1}s\n";
 };
 
 our $RELOAD_WATCHER; # used only during reload
@@ -3944,14 +4008,14 @@
    }
 };
 
-unshift @INC, $LIBDIR;
+#############################################################################
 
 my $bug_warning = 0;
 
 our @WAIT_FOR_TICK;
 our @WAIT_FOR_TICK_BEGIN;
 
-sub wait_for_tick {
+sub wait_for_tick() {
    return Coro::cede if tick_inhibit || $Coro::current == $Coro::main;
 
    my $signal = new Coro::Signal;
@@ -3959,7 +4023,7 @@
    $signal->wait;
 }
 
-sub wait_for_tick_begin {
+sub wait_for_tick_begin() {
    return Coro::cede if tick_inhibit || $Coro::current == $Coro::main;
 
    my $signal = new Coro::Signal;
@@ -3983,7 +4047,7 @@
       Coro::async_pool {
          $Coro::current->{desc} = "runtime saver";
          write_runtime_sync
-            or warn "ERROR: unable to write runtime file: $!";
+            or error "ERROR: unable to write runtime file: $!";
       };
    }
 
@@ -4001,7 +4065,7 @@
       if ($NEXT_TICK) {
          my $jitter = $TICK_START - $NEXT_TICK;
          $JITTER = $JITTER * 0.75 + $jitter * 0.25;
-         warn "jitter $JITTER\n";#d#
+         debug "jitter $JITTER\n";#d#
       }
    }
 }