Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[BUG] OnDemandHandlers cause a traceback at server shutdown #3513

Open
chiizujin opened this issue Apr 19, 2024 · 1 comment
Open

[BUG] OnDemandHandlers cause a traceback at server shutdown #3513

chiizujin opened this issue Apr 19, 2024 · 1 comment
Labels
bug An actual error or unwanted behavior.

Comments

@chiizujin
Copy link
Contributor

chiizujin commented Apr 19, 2024 •
edited

Describe the bug

If an OnDemandHandler is created, its save() call throws an exception. There are two different exceptions depending on whether or not the handler has any stages.

Without stages:

def at_object_creation(self):
      ON_DEMAND_HANDLER.add(self, category="passive_heal")

  File "/home/chiizujin/Games/Evennia/evennia/evennia/utils/picklefield.py", line 101, in dbsafe_encode
    value = dumps(value, protocol=pickle_protocol)
builtins.TypeError: 'NoneType' object is not callable

With stages:

def at_object_creation(self):
    ON_DEMAND_HANDLER.add(self, category="passive_heal", stages={0: "test"})

    value = dumps(value, protocol=pickle_protocol)
builtins.TypeError: cannot pickle 'weakref.ReferenceType' object

Update: I have since seen a third (different) traceback a couple of times, which I have added below. I will add, though, that I am using the exception handling below so that I can keep working on things, and I'm also re-adding the OnDemandHandlers when they are used if I find that they are missing so I don't know if any of that is causing the new traceback. The first two tracebacks above are pre-fiddling.

Other info

I'd also like to suggest the following for consideration to allow the server to shut down in the event of any exceptions being thrown here. Currently, the server will not shut down and has to be killed.

--- a/evennia/server/service.py
+++ b/evennia/server/service.py
@@ -523,7 +523,10 @@ class EvenniaServerService(MultiService):
             # only save monitor state on reload, not on shutdown/reset
             from evennia.scripts.monitorhandler import MONITOR_HANDLER
 
-            MONITOR_HANDLER.save()
+            try:
+                MONITOR_HANDLER.save()
+            except Exception as err:
+                logger.log_trace(f"Error saving MonitorHandler state: {err}")
         else:
             if mode == "reset":
                 # like shutdown but don't unset the is_connected flag and don't disconnect sessions
@@ -553,12 +556,18 @@ class EvenniaServerService(MultiService):
         # tickerhandler state should always be saved.
         from evennia.scripts.tickerhandler import TICKER_HANDLER
 
-        TICKER_HANDLER.save()
+        try:
+            TICKER_HANDLER.save()
+        except Exception as err:
+            logger.log_trace(f"Error saving TickerHandler state: {err}")
 
         # on-demand handler state should always be saved.
         from evennia.scripts.ondemandhandler import ON_DEMAND_HANDLER
 
-        ON_DEMAND_HANDLER.save()
+        try:
+            ON_DEMAND_HANDLER.save()
+        except Exception as err:
+            logger.log_trace(f"Error saving OnDemandHandler state: {err}")
 
         # always called, also for a reload
         self.at_server_stop()

Full tracebacks

Without stages:

2024-04-19 18:39:18 [!!] Unhandled error in Deferred:
2024-04-19 18:39:18 [!!]
	Traceback (most recent call last):
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/twisted/internet/defer.py", line 874, in callback
	    self._startRunCallbacks(result)
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/twisted/internet/defer.py", line 981, in _startRunCallbacks
	    self._runCallbacks()
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/twisted/internet/defer.py", line 1075, in _runCallbacks
	    current.result = callback(  # type: ignore[misc]
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/twisted/internet/defer.py", line 1946, in _gotResultInlineCallbacks
	    _inlineCallbacks(r, gen, status, context)
	--- <exception caught here> ---
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/twisted/internet/defer.py", line 2000, in _inlineCallbacks
	    result = context.run(gen.send, result)
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/server/service.py", line 561, in shutdown
	    ON_DEMAND_HANDLER.save()
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/scripts/ondemandhandler.py", line 401, in save
	    ServerConfig.objects.conf(ONDEMAND_HANDLER_SAVE_NAME, self.tasks)
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/server/manager.py", line 48, in conf
	    conf.value = value  # this will pickle
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/server/models.py", line 102, in __value_set
	    self.save()
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/utils/idmapper/models.py", line 452, in save
	    super().save(*args, **kwargs)
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/base.py", line 814, in save
	    self.save_base(
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/base.py", line 877, in save_base
	    updated = self._save_table(
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/base.py", line 990, in _save_table
	    updated = self._do_update(
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/base.py", line 1054, in _do_update
	    return filtered._update(values) > 0
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/query.py", line 1231, in _update
	    return query.get_compiler(self.db).execute_sql(CURSOR)
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1984, in execute_sql
	    cursor = super().execute_sql(result_type)
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1549, in execute_sql
	    sql, params = self.as_sql()
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1947, in as_sql
	    val = field.get_db_prep_save(val, connection=self.connection)
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/fields/__init__.py", line 954, in get_db_prep_save
	    return self.get_db_prep_value(value, connection=connection, prepared=False)
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/utils/picklefield.py", line 283, in get_db_prep_value
	    value = force_str(dbsafe_encode(value, self.compress, self.protocol))
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/utils/picklefield.py", line 101, in dbsafe_encode
	    value = dumps(value, protocol=pickle_protocol)
	builtins.TypeError: 'NoneType' object is not callable

With stages:

2024-04-19 18:42:00 [!!] Unhandled error in Deferred:
2024-04-19 18:42:00 [!!]
	Traceback (most recent call last):
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/twisted/internet/defer.py", line 874, in callback
	    self._startRunCallbacks(result)
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/twisted/internet/defer.py", line 981, in _startRunCallbacks
	    self._runCallbacks()
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/twisted/internet/defer.py", line 1075, in _runCallbacks
	    current.result = callback(  # type: ignore[misc]
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/twisted/internet/defer.py", line 1946, in _gotResultInlineCallbacks
	    _inlineCallbacks(r, gen, status, context)
	--- <exception caught here> ---
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/twisted/internet/defer.py", line 2000, in _inlineCallbacks
	    result = context.run(gen.send, result)
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/server/service.py", line 561, in shutdown
	    ON_DEMAND_HANDLER.save()
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/scripts/ondemandhandler.py", line 401, in save
	    ServerConfig.objects.conf(ONDEMAND_HANDLER_SAVE_NAME, self.tasks)
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/server/manager.py", line 48, in conf
	    conf.value = value  # this will pickle
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/server/models.py", line 102, in __value_set
	    self.save()
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/utils/idmapper/models.py", line 452, in save
	    super().save(*args, **kwargs)
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/base.py", line 814, in save
	    self.save_base(
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/base.py", line 877, in save_base
	    updated = self._save_table(
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/base.py", line 990, in _save_table
	    updated = self._do_update(
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/base.py", line 1054, in _do_update
	    return filtered._update(values) > 0
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/query.py", line 1231, in _update
	    return query.get_compiler(self.db).execute_sql(CURSOR)
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1984, in execute_sql
	    cursor = super().execute_sql(result_type)
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1549, in execute_sql
	    sql, params = self.as_sql()
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1947, in as_sql
	    val = field.get_db_prep_save(val, connection=self.connection)
	  File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/fields/__init__.py", line 954, in get_db_prep_save
	    return self.get_db_prep_value(value, connection=connection, prepared=False)
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/utils/picklefield.py", line 283, in get_db_prep_value
	    value = force_str(dbsafe_encode(value, self.compress, self.protocol))
	  File "/home/chiizujin/Games/Evennia/evennia/evennia/utils/picklefield.py", line 101, in dbsafe_encode
	    value = dumps(value, protocol=pickle_protocol)
	builtins.TypeError: cannot pickle 'weakref.ReferenceType' object

Additional traceback:

2024-04-21 01:00:04 [!!] Traceback (most recent call last):
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evennia/evennia/server/service.py", line 568, in shutdown
2024-04-21 01:00:04 [!!]     ON_DEMAND_HANDLER.save()
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evennia/evennia/scripts/ondemandhandler.py", line 401, in save
2024-04-21 01:00:04 [!!]     ServerConfig.objects.conf(ONDEMAND_HANDLER_SAVE_NAME, self.tasks)
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evennia/evennia/server/manager.py", line 48, in conf
2024-04-21 01:00:04 [!!]     conf.value = value  # this will pickle
2024-04-21 01:00:04 [!!]     ^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evennia/evennia/server/models.py", line 102, in __value_set
2024-04-21 01:00:04 [!!]     self.save()
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evennia/evennia/utils/idmapper/models.py", line 452, in save
2024-04-21 01:00:04 [!!]     super().save(*args, **kwargs)
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/base.py", line 814, in save
2024-04-21 01:00:04 [!!]     self.save_base(
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/base.py", line 877, in save_base
2024-04-21 01:00:04 [!!]     updated = self._save_table(
2024-04-21 01:00:04 [!!]               ^^^^^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/base.py", line 990, in _save_table
2024-04-21 01:00:04 [!!]     updated = self._do_update(
2024-04-21 01:00:04 [!!]               ^^^^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/base.py", line 1054, in _do_update
2024-04-21 01:00:04 [!!]     return filtered._update(values) > 0
2024-04-21 01:00:04 [!!]            ^^^^^^^^^^^^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/query.py", line 1231, in _update
2024-04-21 01:00:04 [!!]     return query.get_compiler(self.db).execute_sql(CURSOR)
2024-04-21 01:00:04 [!!]            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1984, in execute_sql
2024-04-21 01:00:04 [!!]     cursor = super().execute_sql(result_type)
2024-04-21 01:00:04 [!!]              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1549, in execute_sql
2024-04-21 01:00:04 [!!]     sql, params = self.as_sql()
2024-04-21 01:00:04 [!!]                   ^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1947, in as_sql
2024-04-21 01:00:04 [!!]     val = field.get_db_prep_save(val, connection=self.connection)
2024-04-21 01:00:04 [!!]           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evenv/lib/python3.11/site-packages/django/db/models/fields/__init__.py", line 954, in get_db_prep_save
2024-04-21 01:00:04 [!!]     return self.get_db_prep_value(value, connection=connection, prepared=False)
2024-04-21 01:00:04 [!!]            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evennia/evennia/utils/picklefield.py", line 283, in get_db_prep_value
2024-04-21 01:00:04 [!!]     value = force_str(dbsafe_encode(value, self.compress, self.protocol))
2024-04-21 01:00:04 [!!]                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evennia/evennia/utils/picklefield.py", line 95, in dbsafe_encode
2024-04-21 01:00:04 [!!]     value = deepcopy(value)
2024-04-21 01:00:04 [!!]             ^^^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/usr/lib/python3.11/copy.py", line 146, in deepcopy
2024-04-21 01:00:04 [!!]     y = copier(x, memo)
2024-04-21 01:00:04 [!!]         ^^^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/usr/lib/python3.11/copy.py", line 231, in _deepcopy_dict
2024-04-21 01:00:04 [!!]     y[deepcopy(key, memo)] = deepcopy(value, memo)
2024-04-21 01:00:04 [!!]                              ^^^^^^^^^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/usr/lib/python3.11/copy.py", line 172, in deepcopy
2024-04-21 01:00:04 [!!]     y = _reconstruct(x, memo, *rv)
2024-04-21 01:00:04 [!!]         ^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/usr/lib/python3.11/copy.py", line 271, in _reconstruct
2024-04-21 01:00:04 [!!]     state = deepcopy(state, memo)
2024-04-21 01:00:04 [!!]             ^^^^^^^^^^^^^^^^^^^^^

(The previous 4 repeat many times)

2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evennia/evennia/utils/optionhandler.py", line 89, in __getattr__
2024-04-21 01:00:04 [!!]     return self.get(key)
2024-04-21 01:00:04 [!!]            ^^^^^^^^^^^^^
2024-04-21 01:00:04 [!!]   File "/home/chiizujin/Games/Evennia/evennia/evennia/utils/optionhandler.py", line 137, in get
2024-04-21 01:00:04 [!!]     if key not in self.options_dict:
2024-04-21 01:00:04 [!!]                   ^^^^^^^^^^^^^^^^^

(Repeating until...)

2024-04-21 01:00:04 [!!] RecursionError: maximum recursion depth exceeded
@chiizujin chiizujin added bug An actual error or unwanted behavior. needs-triage Yet to be looked at and verified as an a real issue/feature that could be worked on labels Apr 19, 2024
@Griatch Griatch removed the needs-triage Yet to be looked at and verified as an a real issue/feature that could be worked on label Apr 27, 2024
@Griatch
Copy link
Member

Griatch commented Apr 27, 2024

Confirmed this, have a fix in the works, nothing ready yet though.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug An actual error or unwanted behavior.
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@Griatch @chiizujin