LorenFrankLab / spyglass

Neuroscience data analysis framework for reproducible research built by Loren Frank Lab at UCSF
https://lorenfranklab.github.io/spyglass/
MIT License
94 stars 43 forks source link

DJ's `topo_sort` mechanisms not interchangable in `RestrGraph` #1161

Closed rpswenson closed 1 month ago

rpswenson commented 1 month ago

Describe the bug When populating the SpikeSorting table, the key is not found

To Reproduce

sss_pk = {'sorting_id': '50c746ab-4571-4118-a02c-c6572ce8359d'}
sgs.SpikeSorting.populate(sss_pk)

Error stack:

KeyError                                  Traceback (most recent call last)
Cell In[7], line 2
      1 sss_pk = {'sorting_id': '50c746ab-4571-4118-a02c-c6572ce8359d'}
----> 2 sgs.SpikeSorting.populate(sss_pk)

File ~/spyglass/src/spyglass/utils/dj_mixin.py:603, in SpyglassMixin.populate(self, *restrictions, **kwargs)
    598     keys = (self._jobs_to_do(restrictions) - self.target).fetch(
    599         "KEY", limit=kwargs.get("limit", None)
    600     )
    602 if use_transact is False:
--> 603     upstream_hash = self._hash_upstream(keys)
    604     if kwargs:  # Warn of ignoring populate kwargs, bc using `make`
    605         logger.warning(
    606             "Ignoring kwargs when not using transaction protection."
    607         )

File ~/spyglass/src/spyglass/utils/dj_mixin.py:559, in SpyglassMixin._hash_upstream(self, keys)
    549     raise RuntimeError("No upstream tables found for upstream hash.")
    551 leaves = {  # Restriction on each primary parent
    552     p.full_table_name: [
    553         {k: v for k, v in key.items() if k in p.heading.names}
   (...)
    556     for p in parents
    557 }
--> 559 return RestrGraph(seed_table=self, leaves=leaves, cascade=True).hash

File ~/spyglass/src/spyglass/utils/dj_graph.py:590, in RestrGraph.__init__(self, seed_table, leaves, destinations, direction, cascade, verbose, **kwargs)
    588 for dir in dir_list:
    589     self._log_truncate(f"Start {dir:<4} : {self.leaves}")
--> 590     self.cascade(direction=dir)
    591     self.cascaded = False
    592     self.visited -= self.leaves

File ~/spyglass/src/spyglass/utils/dj_graph.py:748, in RestrGraph.cascade(self, show_progress, direction, warn)
    745     self.cascade1(table, restr, direction=direction)
    747 self.cascaded = True  # Mark here so next step can use `restr_ft`
--> 748 self.cascade_files()

File ~/spyglass/src/spyglass/utils/dj_graph.py:762, in RestrGraph.cascade_files(self)
    760 """Set node attribute for analysis files."""
    761 analysis_pk = self.analysis_file_tbl.primary_key
--> 762 for ft in self.restr_ft:
    763     if not set(analysis_pk).issubset(ft.heading.names):
    764         continue

File ~/spyglass/src/spyglass/utils/dj_graph.py:501, in AbstractGraph.restr_ft(self)
    498 @property
    499 def restr_ft(self):
    500     """Get non-empty restricted FreeTables from all visited nodes."""
--> 501     return [ft for ft in self.all_ft if len(ft) > 0]

File ~/spyglass/src/spyglass/utils/dj_graph.py:495, in AbstractGraph.all_ft(self)
    491 self.cascade(warn=False)
    492 nodes = [n for n in self.visited if not n.isnumeric()]
    493 return [
    494     self._get_ft(table, with_restr=True, warn=False)
--> 495     for table in self._topo_sort(nodes, subgraph=True, reverse=False)
    496 ]

File ~/spyglass/src/spyglass/utils/dj_graph.py:480, in AbstractGraph._topo_sort(self, nodes, subgraph, reverse)
    474 nodes = [
    475     node
    476     for node in ensure_names(nodes)
    477     if not self._is_out(node, warn=False)
    478 ]
    479 graph = self.graph.subgraph(nodes) if subgraph else self.graph
--> 480 ordered = dj_topo_sort(graph)
    481 if reverse:
    482     ordered.reverse()

File ~/miniforge3/envs/spyglass/lib/python3.9/site-packages/datajoint/dependencies.py:20, in unite_master_parts(lst)
      9 """
     10 re-order a list of table names so that part tables immediately follow their master tables without breaking
     11 the topological order.
   (...)
     17     ['`s`.`a`', '`s`.`a__q`', '`s`.`a__r`', '`s`.`b`', '`s`.`b__q`', '`s`.`c`', '`s`.`c__q`', '`s`.`d`']
     18 """
     19 for i in range(2, len(lst)):
---> 20     name = lst[i]
     21     match = re.match(r"(?P<master>`\w+`.`#?\w+)__\w+`", name)
     22     if match:  # name is a part table

File ~/miniforge3/envs/spyglass/lib/python3.9/site-packages/networkx/classes/graph.py:513, in Graph.__getitem__(self, n)
    489 def __getitem__(self, n):
    490     """Returns a dict of neighbors of node n.  Use: 'G[n]'.
    491 
    492     Parameters
   (...)
    511     AtlasView({1: {}})
    512     """
--> 513     return self.adj[n]

File ~/miniforge3/envs/spyglass/lib/python3.9/site-packages/networkx/classes/coreviews.py:81, in AdjacencyView.__getitem__(self, name)
     80 def __getitem__(self, name):
---> 81     return AtlasView(self._atlas[name])

File ~/miniforge3/envs/spyglass/lib/python3.9/site-packages/networkx/classes/coreviews.py:320, in FilterAdjacency.__getitem__(self, node)
    317         return self.NODE_OK(nbr) and self.EDGE_OK(node, nbr)
    319     return FilterAtlas(self._atlas[node], new_node_ok)
--> 320 raise KeyError(f"Key {node} not found")

KeyError: 'Key 2 not found'

Honestly no idea what's happening here. The sorting id shows up as expected in SpikeSortingSelection and I wasn't able to glean much from %debug

CBroz1 commented 1 month ago

looking over the stack, I'm seeing...

  1. A triggering of the no-transaction populate process
  2. An attempt to generate the hash that replaces transaction protections
  3. An attempt to sort the graph
  4. An attempt to fetch a numeric node 2, which is an alias node in the table graph, and shouldn't get called

DataJoint changed their sort mechanism in 14.2 - what version are you using? Do you still get this error if you fetch updates from their github?

When I run this key, I see a different error stack, which I assume is folder permission issue - I get past the hasher and instead have problems with spikeinterface

Stack ```python [13:57:37][WARNING] Spyglass: Please update position_tools to >= 0.1.0 [13:57:39][WARNING] Spyglass: Turning off transaction protection this table by default. Use use_transation=True to re-enable. Read more about transactions: https://docs.datajoint.io/python/definition/05-Transactions.html https://github.com/LorenFrankLab/spyglass/issues/1030 [2024-10-09 13:57:42,313][WARNING]: Skipped checksum for file with hash: b076a96c-c07a-9e37-1ba2-4cb78e752b6b, and path: /stelmo/nwb/raw/RS1220240814_.nwb [2024-10-09 13:57:42,331][WARNING]: Skipped checksum for file with hash: 48ee47b5-fadc-3a33-f26b-a59d01ea538f, and path: /stelmo/nwb/analysis/RS1220240814/RS1220240814_SSSOHYSJZS.nwb [2024-10-09 13:57:42,401][WARNING]: Skipped checksum for file with hash: 48ee47b5-fadc-3a33-f26b-a59d01ea538f, and path: /stelmo/nwb/analysis/RS1220240814/RS1220240814_SSSOHYSJZS.nwb /home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/hdmf/spec/namespace.py:531: UserWarning: Ignoring cached namespace 'hdmf-common' version 1.8.0 because version 1.6.0 is already loaded. warn("Ignoring cached namespace '%s' version %s because version %s is already loaded." /home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/hdmf/spec/namespace.py:531: UserWarning: Ignoring cached namespace 'hdmf-experimental' version 0.5.0 because version 0.3.0 is already loaded. warn("Ignoring cached namespace '%s' version %s because version %s is already loaded." /home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/hdmf/spec/namespace.py:531: UserWarning: Ignoring cached namespace 'hdmf-common' version 1.8.0 because version 1.6.0 is already loaded. warn("Ignoring cached namespace '%s' version %s because version %s is already loaded." /home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/hdmf/spec/namespace.py:531: UserWarning: Ignoring cached namespace 'hdmf-experimental' version 0.5.0 because version 0.3.0 is already loaded. warn("Ignoring cached namespace '%s' version %s because version %s is already loaded." Mountainsort4 use the OLD spikeextractors mapped with NewToOldRecording [2024-10-09 13:58:53,538][INFO]: Connecting root@localhost:3307 [13:58:53][ERROR] Spyglass: Uncaught exception Traceback (most recent call last): File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/pymysql/connections.py", line 616, in connect sock = socket.create_connection( File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/socket.py", line 844, in create_connection raise err File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/socket.py", line 832, in create_connection sock.connect(sa) ConnectionRefusedError: [Errno 111] Connection refused During handling of the above exception, another exception occurred: Traceback (most recent call last): File "", line 1, in File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/multiprocessing/spawn.py", line 116, in spawn_main exitcode = _main(fd, parent_sentinel) File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/multiprocessing/spawn.py", line 125, in _main prepare(preparation_data) File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/multiprocessing/spawn.py", line 236, in prepare _fixup_main_from_path(data['init_main_from_path']) File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/multiprocessing/spawn.py", line 287, in _fixup_main_from_path main_content = runpy.run_path(main_path, File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/runpy.py", line 288, in run_path return _run_module_code(code, init_globals, run_name, File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/runpy.py", line 97, in _run_module_code _run_code(code, mod_globals, init_globals, File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/runpy.py", line 87, in _run_code exec(code, run_globals) File "/home/cbroz/wrk/spyglass/temp-issue.py", line 1, in from spyglass.spikesorting import v1 as sgs File "/home/cbroz/wrk/spyglass/src/spyglass/spikesorting/v1/__init__.py", line 1, in from spyglass.spikesorting.imported import ImportedSpikeSorting File "/home/cbroz/wrk/spyglass/src/spyglass/spikesorting/imported.py", line 7, in from spyglass.common.common_nwbfile import Nwbfile File "/home/cbroz/wrk/spyglass/src/spyglass/common/__init__.py", line 3, in from spyglass.common.common_behav import ( File "/home/cbroz/wrk/spyglass/src/spyglass/common/common_behav.py", line 11, in from spyglass.common.common_device import CameraDevice File "/home/cbroz/wrk/spyglass/src/spyglass/common/common_device.py", line 9, in schema = dj.schema("common_device") File "/home/cbroz/wrk/datajoint-python/datajoint/schemas.py", line 77, in __init__ self.activate(schema_name) File "/home/cbroz/wrk/datajoint-python/datajoint/schemas.py", line 119, in activate self.connection = conn() File "/home/cbroz/wrk/datajoint-python/datajoint/connection.py", line 134, in conn conn.connection = Connection(host, user, password, None, init_fun, use_tls) File "/home/cbroz/wrk/datajoint-python/datajoint/connection.py", line 196, in __init__ connect_host_hook(self) File "/home/cbroz/wrk/datajoint-python/datajoint/connection.py", line 53, in connect_host_hook connection_obj.connect() File "/home/cbroz/wrk/datajoint-python/datajoint/connection.py", line 220, in connect self._conn = client.connect( File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/pymysql/connections.py", line 352, in __init__ self.connect() File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/pymysql/connections.py", line 668, in connect raise exc pymysql.err.OperationalError: (2003, "Can't connect to MySQL server on 'localhost' ([Errno 111] Connection refused)") --------------------------------------------------------------------------- SpikeSortingError Traceback (most recent call last) File ~/wrk/spyglass/temp-issue.py:4 1 from spyglass.spikesorting import v1 as sgs 3 sss_pk = {"sorting_id": "50c746ab-4571-4118-a02c-c6572ce8359d"} ----> 4 sgs.SpikeSorting.populate(sss_pk) File ~/wrk/spyglass/src/spyglass/utils/dj_mixin.py:615, in SpyglassMixin.populate(self, *restrictions, **kwargs) 613 else: # No transaction protection, use bare make 614 for key in keys: --> 615 self.make(key) 616 if upstream_hash != self._hash_upstream(keys): 617 (self & keys).delete(safemode=False) File ~/wrk/spyglass/src/spyglass/spikesorting/v1/sorting.py:284, in SpikeSorting.make(self, key) 278 sorting = sis.run_sorter( 279 **common_sorter_items, 280 singularity_image=True, 281 **sorter_params, 282 ) 283 else: --> 284 sorting = sis.run_sorter( 285 **common_sorter_items, 286 **sorter_params, 287 ) 288 key["time_of_sort"] = int(time.time()) 289 sorting = sic.remove_excess_spikes(sorting, recording) File ~/miniconda3/envs/spy/lib/python3.9/site-packages/spikeinterface/sorters/runsorter.py:147, in run_sorter(sorter_name, recording, output_folder, remove_existing_folder, delete_output_folder, verbose, raise_error, docker_image, singularity_image, delete_container_files, with_output, **sorter_params) 140 container_image = singularity_image 141 return run_sorter_container( 142 container_image=container_image, 143 mode=mode, 144 **common_kwargs, 145 ) --> 147 return run_sorter_local(**common_kwargs) File ~/miniconda3/envs/spy/lib/python3.9/site-packages/spikeinterface/sorters/runsorter.py:173, in run_sorter_local(sorter_name, recording, output_folder, remove_existing_folder, delete_output_folder, verbose, raise_error, with_output, **sorter_params) 171 SorterClass.set_params_to_folder(recording, output_folder, sorter_params, verbose) 172 SorterClass.setup_recording(recording, output_folder, verbose=verbose) --> 173 SorterClass.run_from_folder(output_folder, raise_error, verbose) 174 if with_output: 175 sorting = SorterClass.get_result_from_folder(output_folder) File ~/miniconda3/envs/spy/lib/python3.9/site-packages/spikeinterface/sorters/basesorter.py:289, in BaseSorter.run_from_folder(cls, output_folder, raise_error, verbose) 286 print(f"{sorter_name} run time {run_time:0.2f}s") 288 if has_error and raise_error: --> 289 raise SpikeSortingError( 290 f"Spike sorting error trace:\n{log['error_trace']}\n" 291 f"Spike sorting failed. You can inspect the runtime trace in {output_folder}/spikeinterface_log.json." 292 ) 294 return run_time SpikeSortingError: Spike sorting error trace: Traceback (most recent call last): File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/spikeinterface/sorters/basesorter.py", line 254, in run_from_folder SorterClass._run_from_folder(sorter_output_folder, sorter_params, verbose) File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/spikeinterface/sorters/external/mountainsort4.py", line 136, in _run_from_folder old_api_sorting = mountainsort4.mountainsort4(**ms4_params) File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/mountainsort4/mountainsort4.py", line 44, in mountainsort4 MS4.sort() File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/mountainsort4/ms4alg.py", line 858, in sort dask.compute(*dask_list, num_workers=self._num_workers) File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/dask/base.py", line 595, in compute results = schedule(dsk, keys, **kwargs) File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/dask/multiprocessing.py", line 233, in get result = get_async( File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/site-packages/dask/local.py", line 500, in get_async for key, res_info, failed in queue_get(queue).result(): File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/concurrent/futures/_base.py", line 439, in result return self.__get_result() File "/home/cbroz/miniconda3/envs/spy/lib/python3.9/concurrent/futures/_base.py", line 391, in __get_result raise self._exception concurrent.futures.process.BrokenProcessPool: A process in the process pool was terminated abruptly while the future was running or pending. Spike sorting failed. You can inspect the runtime trace in /stelmo/nwb/tmp/tmppfbrfl7x/spikeinterface_log.json. ```
rpswenson commented 1 month ago

Huh. When I checked my version it looks like I'm on 14.2 but I'm still getting the same error even after a jupyter refresh dj.__version__ '0.14.2'

CBroz1 commented 1 month ago

Does it change if you pull from github? This would mean ...

cd someplace_to_download_dj
git clone https://github.com/datajoint/datajoint-python/
pip install ./datajoint-python
rpswenson commented 1 month ago

Yes, I ran the above in a terminal and refreshed my notebook but am getting the same error stack

CBroz1 commented 1 month ago

If your dj and spyglass are both up to date, I'm not sure why we would see different error messages. Does the error change if this is the only table you import?

If not, let's find a time where I can %debug on your machine. This step: nodes = [n for n in self.visited if not n.isnumeric()] should be filtering out the 2 node. It would be helpful to know if it was present in the list at dj_graph.py:480 or if it was introduced after calling dj's sorter

rpswenson commented 1 month ago

Yeah, even if I only import dj and sgs I get the key 2 error

CBroz1 commented 1 month ago

fixed with #1162