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.

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

Audio narration #673

Merged
merged 9 commits into from
Jun 4, 2024
Merged

Conversation

KIRA009
Copy link
Contributor

@KIRA009 KIRA009 commented May 15, 2024

What kind of change does this PR introduce?
This PR adds the ability to record audio when recording actions.

Summary
This is a cleaned up and updated PR, taken from #346 . This adds a new process which records the audio narrated by the user while recording, then transcribes it using openai's whisper model, and saves relevant information to the database. A follow up PR would display the transcribed text along with the actions during which they were narrated.

Checklist

  • My code follows the style guidelines of OpenAdapt
  • I have performed a self-review of my code
  • If applicable, I have added tests to prove my fix is functional/effective
  • I have linted my code locally prior to submission
  • I have commented my code, particularly in hard-to-understand areas
  • I have made corresponding changes to the documentation (e.g. README.md, requirements.txt)
  • New and existing unit tests pass locally with my changes

How can your code be run and tested?

Other information

@abrichr
Copy link
Contributor

abrichr commented May 16, 2024

Thanks @KIRA009 ! I tried running a recording with this, but it seems to hang:

2024-05-16 15:39:57.576 | DEBUG    | openadapt.video:write_video_frame:118 - time_diff=6.378242254257202 pts=153 video_stream.average_rate=Fraction(24, 1)
2024-05-16 15:39:57.725 | INFO     | __main__:on_press:961 - Stop sequence entered! Stopping recording now.
2024-05-16 15:39:57.731 | DEBUG    | __mp_main__:write_events:431 - event_type='action' written
2024-05-16 15:39:57.761 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written
2024-05-16 15:39:57.786 | DEBUG    | __mp_main__:write_events:431 - event_type='action' written
2024-05-16 15:39:57.803 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written
2024-05-16 15:39:57.807 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written
2024-05-16 15:39:57.826 | DEBUG    | openadapt.video:write_video_frame:107 - timestamp=1715899197.0623374 video_start_timestamp=1715899190.586895
2024-05-16 15:39:57.831 | DEBUG    | openadapt.video:write_video_frame:118 - time_diff=6.475442409515381 pts=155 video_stream.average_rate=Fraction(24, 1)
2024-05-16 15:39:57.957 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written
2024-05-16 15:39:57.976 | DEBUG    | openadapt.video:write_video_frame:107 - timestamp=1715899197.1246996 video_start_timestamp=1715899190.586895
2024-05-16 15:39:57.982 | DEBUG    | openadapt.video:write_video_frame:118 - time_diff=6.53780460357666 pts=156 video_stream.average_rate=Fraction(24, 1)
2024-05-16 15:39:58.146 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written
2024-05-16 15:39:58.172 | DEBUG    | openadapt.video:write_video_frame:107 - timestamp=1715899197.6674418 video_start_timestamp=1715899190.586895
2024-05-16 15:39:58.180 | DEBUG    | openadapt.video:write_video_frame:118 - time_diff=7.080546855926514 pts=169 video_stream.average_rate=Fraction(24, 1)
2024-05-16 15:39:58.374 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written
2024-05-16 15:39:58.398 | DEBUG    | openadapt.video:write_video_frame:107 - timestamp=1715899197.7157722 video_start_timestamp=1715899190.586895
2024-05-16 15:39:58.403 | DEBUG    | openadapt.video:write_video_frame:118 - time_diff=7.12887716293335 pts=171 video_stream.average_rate=Fraction(24, 1)
2024-05-16 15:39:58.476 | INFO     | __mp_main__:write_events:439 - event_type='screen' done
2024-05-16 15:39:58.476 | INFO     | __mp_main__:wrapper_logging:146 -  <- Leave: write_events(None)
2024-05-16 15:39:58.476 | INFO     | __main__:record:1373 - joining...
2024-05-16 15:39:58.478 | INFO     | __mp_main__:write_events:439 - event_type='window' done
2024-05-16 15:39:58.478 | INFO     | __mp_main__:wrapper_logging:146 -  <- Leave: write_events(None)
Writing action events...:   0%|                                                                                                                                                              | 0/34 [00:00<?, ?event/s]
2024-05-16 15:39:58.480 | INFO     | __main__:wrapper_logging:146 -  <- Leave: read_window_events(None)
Writing action events...: 100%|██████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 34/34 [00:00<00:00, 40582.34event/s]
2024-05-16 15:39:58.482 | INFO     | __mp_main__:write_events:439 - event_type='action' done
2024-05-16 15:39:58.482 | INFO     | __mp_main__:wrapper_logging:146 -  <- Leave: write_events(None)
2024-05-16 15:39:58.520 | INFO     | __main__:read_screen_events:705 - Done
2024-05-16 15:39:58.521 | INFO     | __main__:process_events:291 - Done
2024-05-16 15:39:58.522 | INFO     | __main__:wrapper_logging:146 -  <- Leave: process_events(None)
2024-05-16 15:39:58.613 | INFO     | __mp_main__:record_audio:1087 - Transcribing audio...
2024-05-16 15:39:58.620 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written
2024-05-16 15:39:58.620 | INFO     | openadapt.video:finalize_video_writer:157 - flushing video stream...
2024-05-16 15:39:58.726 | INFO     | openadapt.video:close_container:150 - closing video container...
2024-05-16 15:39:58.730 | INFO     | openadapt.video:finalize_video_writer:166 - done
2024-05-16 15:39:58.730 | INFO     | __mp_main__:write_events:439 - event_type='screen' done
2024-05-16 15:39:58.730 | INFO     | __mp_main__:wrapper_logging:146 -  <- Leave: write_events(None)
 64%|████████████████████████▎             | 88.8M/139M [00:18<00:09, 5.42MiB/s]
 84%|████████████████████████████████▉      | 117M/139M [00:23<00:04, 5.46MiB/s]
100%|███████████████████████████████████████| 139M/139M [00:28<00:00, 5.17MiB/s]
OMP: Info #276: omp_set_nested routine deprecated, please use omp_set_max_active_levels instead.
image

Any suggestions?

@KIRA009
Copy link
Contributor Author

KIRA009 commented May 20, 2024

@abrichr It could possibly be because the first time the model is downloaded it takes some time, how long was it in this state?

@abrichr
Copy link
Contributor

abrichr commented May 20, 2024

how long was it in this state

~5min before I killed it.

Upon trying again I am no longer experiencing this issue, and the recording completes, modulo this exception:

2024-05-20 10:52:55.839 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written                                                                                                      10:52:56 [22/1774]
2024-05-20 10:52:55.860 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written     
2024-05-20 10:52:55.864 | DEBUG    | openadapt.video:write_video_frame:107 - timestamp=1716216774.9314291 video_start_timestamp=1716216770.5124972
2024-05-20 10:52:55.872 | DEBUG    | openadapt.video:write_video_frame:118 - time_diff=4.41893196105957 pts=106 video_stream.average_rate=Fraction(24, 1)                                                              ^CProcess Process-5:                                                                                       
Traceback (most recent call last):                                                                         
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/process.py", line 314, in _bootstrap                                                            
    self.run()                                                                                             
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)                                                              
  File "/Users/abrichr/oa/OpenAdapt/openadapt/record.py", line 1078, in record_audio           
    terminate_processing.wait()                                                                                                                                                                                        
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/synchronize.py", line 349, in wait
    self._cond.wait(timeout)                                                                               
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/synchronize.py", line 261, in wait
    return self._wait_semaphore.acquire(True, timeout)                                                                                                                                                                 
KeyboardInterrupt    

However, when running openadapt.visualize:

  File "/Users/abrichr/oa/OpenAdapt/openadapt/visualize.py", line 188, in main                                                                                                                                         
    audio_info = row2dict(crud.get_audio_info(recording))                                                  
                 |        |    |              -> Recording(id=5, timestamp=1716216770.411662, monitor_width=1512, monitor_height=982, double_click_interval_seconds=0.5, doubl...                                      
                 |        |    -> <function get_audio_info at 0x160242050>                                                                                                                                             
                 |        -> <module 'openadapt.db.crud' from '/Users/abrichr/oa/OpenAdapt/openadapt/db/crud.py'>                                                                                                      
                 -> <function row2dict at 0x15d6c37f0>                                                                                                                                                                 
                                                                                                                                                                                                                       
  File "/Users/abrichr/oa/OpenAdapt/openadapt/db/crud.py", line 541, in get_audio_info                                                                                                      
    return _get(AudioInfo, recording_timestamp, _db)                                                                                                                                                                   
           |    |          |                    -> <sqlalchemy.orm.session.Session object at 0x160238610>                                                                                                              
           |    |          -> Recording(id=5, timestamp=1716216770.411662, monitor_width=1512, monitor_height=982, double_click_interval_seconds=0.5, doubl...                                                         
           |    -> <class 'openadapt.models.AudioInfo'>                                                                                                                                                                
           -> <function _get at 0x160241ab0>                                                               
                                                                                                                                                                                                                       
  File "/Users/abrichr/oa/OpenAdapt/openadapt/db/crud.py", line 299, in _get                                                                                                                                           
    .all()                                                                                                                                                                                                                                                                                                                                                                              
                                                                                                           
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/query.py", line 2772, in all                                                                                                                                                                                                                           
    return self._iter().all()                                                                                                                                                                                          
           |    -> <function Query._iter at 0x14a5f6e60>                                                                                                                                                               
           -> <sqlalchemy.orm.query.Query object at 0x165d80370>                                                                                                                                                       
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/query.py", line 2915, in _iter                                                                                                                                                                                                                         
    result = self.session.execute(                                                                                                                                                                                     
             |    |       -> <function Session.execute at 0x14a659120>                                     
             |    -> <sqlalchemy.orm.session.Session object at 0x160238610>                                
             -> <sqlalchemy.orm.query.Query object at 0x165d80370>                                                                                                                                                     
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/sqlalchemy/orm/session.py", line 1714, in execute                                                    
    result = conn._execute_20(statement, params or {}, execution_options)                                                                                                                                              
             |    |           |          |             -> immutabledict({'_sa_orm_load_options': default_load_options(_legacy_uniquing=True), '_result_disable_adapt_to_context': True,...                             
             |    |           |          -> immutabledict({})                                                                                                                               
             |    |           -> <sqlalchemy.sql.selectable.Select object at 0x165e15e40>                                                                                                                                                                                                                                                                                               
             |    -> <function Connection._execute_20 at 0x14a369510>                                                        
             -> <sqlalchemy.engine.base.Connection object at 0x165dd9ba0>                                                                                                                   
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1705, in _execute_20                                                                                   
    return meth(self, args_10style, kwargs_10style, execution_options)                                                                                                                                                                                                                                                                                                                  
           |    |     |             |               -> immutabledict({'_sa_orm_load_options': default_load_options(_legacy_uniquing=True), '_result_disable_adapt_to_context': True,...                                                                   
           |    |     |             -> immutabledict({})                                                                     
           |    |     -> ({},)                                                                                                                                                                                                                                                                                                                                                          
           |    -> <sqlalchemy.engine.base.Connection object at 0x165dd9ba0>                                                                                                                                                                                                                                                                                                            
           -> <bound method ClauseElement._execute_on_connection of <sqlalchemy.sql.selectable.Select object at 0x165e15e40>>                                                                                                                             
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/sqlalchemy/sql/elements.py", line 333, in _execute_on_connection                                                                                                                                                                                                      
    return connection._execute_clauseelement(                                                 
           |          -> <function Connection._execute_clauseelement at 0x14a369360>                                                                                                                                                                                                                                                                                                    
           -> <sqlalchemy.engine.base.Connection object at 0x165dd9ba0>                                                                                                                                                                                                                                                                                                                 
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1572, in _execute_clauseelement                                                                        
    ret = self._execute_context(                                                                                                                                                                                                                                                                                                                                                        
          |    -> <function Connection._execute_context at 0x14a369630>                                                      
          -> <sqlalchemy.engine.base.Connection object at 0x165dd9ba0>                                                                                                                      
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1806, in _execute_context                                                                                                                                                                                                            
    self._handle_dbapi_exception(                                                             
    |    -> <function Connection._handle_dbapi_exception at 0x14a3697e0>                                                                                                                    
    -> <sqlalchemy.engine.base.Connection object at 0x165dd9ba0>                                                             
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 2124, in _handle_dbapi_exception                                                                                                                                                                                                     
    util.raise_(                                                                                                                                                                                                                                                                                                                                                                        
    |    -> <function raise_ at 0x149f69bd0>                                                  
    -> <module 'sqlalchemy.util' from '/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/s...                                                                                                                   
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/sqlalchemy/util/compat.py", line 208, in raise_                                                                                         
    raise exception                                                                           
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/sqlalchemy/engine/base.py", line 1800, in _execute_context                                                                              
    context = constructor(                                                                                                   
              -> <bound method DefaultExecutionContext._init_compiled of <class 'sqlalchemy.dialects.sqlite.base.SQLiteExecutionContext'>>                                                                                                                
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 1077, in _init_compiled                                                                             
    param = [                                                                                                                                                                               
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/sqlalchemy/engine/default.py", line 1078, in <listcomp>                                                                                 
    processors[key](compiled_params[key])                                                                                    
    |          |    |               -> 'recording_timestamp_1'                                                               
    |          |    -> {'recording_timestamp_1': Recording(id=5, timestamp=1716216770.411662, monitor_width=1512, monitor_height=982, double_click_i...                                                                                                   
    |          -> 'recording_timestamp_1'                                                                                    
    -> {'recording_timestamp_1': <built-in function to_float>}                                                               

sqlalchemy.exc.StatementError: (builtins.TypeError) float() argument must be a string or a real number, not 'Recording'                                                                                                                                   
[SQL: SELECT audio_info.id AS audio_info_id, audio_info.timestamp AS audio_info_timestamp, audio_info.flac_data AS audio_info_flac_data, audio_info.transcribed_text AS audio_info_transcribed_text, audio_info.recording_timestamp AS audio_info_recording_timestamp, audio_info.sample_rate AS audio_info_sample_rate, audio_info.words_with_timestamps AS audio_info_words_with_timestamps 
FROM audio_info                                                                                                              
WHERE audio_info.recording_timestamp = ? ORDER BY audio_info.timestamp]                                                      
[parameters: [{}]] 

(I have run alembic upgrade head.)

@KIRA009
Copy link
Contributor Author

KIRA009 commented May 20, 2024

@abrichr my fault. I manually added the timestamp column in the migration file, as the PR is still in review. You would have to downgrade the latest migration and upgrade it again.

@abrichr
Copy link
Contributor

abrichr commented May 21, 2024

@KIRA009 when pressing ctrl+c during recording I get this:

2024-05-20 10:52:55.839 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written                                                                                                      10:52:56 [22/1774]
2024-05-20 10:52:55.860 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written     
2024-05-20 10:52:55.864 | DEBUG    | openadapt.video:write_video_frame:107 - timestamp=1716216774.9314291 video_start_timestamp=1716216770.5124972
2024-05-20 10:52:55.872 | DEBUG    | openadapt.video:write_video_frame:118 - time_diff=4.41893196105957 pts=106 video_stream.average_rate=Fraction(24, 1)                                                              ^CProcess Process-5:                                                                                       
Traceback (most recent call last):                                                                         
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/process.py", line 314, in _bootstrap                                                            
    self.run()                                                                                             
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/process.py", line 108, in run
    self._target(*self._args, **self._kwargs)                                                              
  File "/Users/abrichr/oa/OpenAdapt/openadapt/record.py", line 1078, in record_audio           
    terminate_processing.wait()                                                                                                                                                                                        
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/synchronize.py", line 349, in wait
    self._cond.wait(timeout)                                                                               
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/synchronize.py", line 261, in wait
    return self._wait_semaphore.acquire(True, timeout)                                                                                                                                                                 
KeyboardInterrupt    

I believe we need to follow this pattern used elsewhere in record.py:

signal.signal(signal.SIGINT, signal.SIG_IGN)

After adding this, I no longer get the error, but the process hangs:

^C2024-05-21 11:24:23.207 | INFO     | __main__:record:1376 - joining...
Writing window events...: 100%|████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 1/1 [00:00<00:00, 3788.89event/s]
2024-05-21 11:24:23.210 | INFO     | __mp_main__:write_events:439 - event_type='window' done
2024-05-21 11:24:23.210 | INFO     | __mp_main__:wrapper_logging:146 -  <- Leave: write_events(None)
2024-05-21 11:24:23.210 | DEBUG    | __mp_main__:write_events:431 - event_type='action' written
Writing action events...: 100%|██████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 229/229 [00:00<00:00, 162630.48event/s]
2024-05-21 11:24:23.210 | INFO     | __main__:wrapper_logging:146 -  <- Leave: read_window_events(None)
2024-05-21 11:24:23.211 | INFO     | __mp_main__:write_events:439 - event_type='action' done
2024-05-21 11:24:23.211 | INFO     | __mp_main__:wrapper_logging:146 -  <- Leave: write_events(None)
2024-05-21 11:24:23.222 | INFO     | __main__:read_screen_events:705 - Done
2024-05-21 11:24:23.223 | INFO     | __main__:process_events:291 - Done
2024-05-21 11:24:23.224 | INFO     | __main__:wrapper_logging:146 -  <- Leave: process_events(None)
2024-05-21 11:24:23.239 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written
Writing screen events...: 100%|██████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 68/68 [00:00<00:00, 2164.21event/s]
2024-05-21 11:24:23.240 | INFO     | __mp_main__:write_events:439 - event_type='screen' done
2024-05-21 11:24:23.240 | INFO     | __mp_main__:wrapper_logging:146 -  <- Leave: write_events(None)
2024-05-21 11:24:23.250 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written
Writing screen(video) events...:   0%|                                                                                                                                                                                          | 0/68 [00:00<?, ?event/s]
2024-05-21 11:24:23.284 | DEBUG    | openadapt.video:write_video_frame:107 - timestamp=1716305062.984825 video_start_timestamp=1716305047.3683443
2024-05-21 11:24:23.288 | DEBUG    | openadapt.video:write_video_frame:118 - time_diff=15.616480588912964 pts=374 video_stream.average_rate=Fraction(24, 1)
2024-05-21 11:24:23.390 | INFO     | __mp_main__:record_audio:1089 - Transcribing audio...
Writing screen(video) events...:  99%|█████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████▍  | 67/68 [00:00<00:00, 371.62event/s]
2024-05-21 11:24:23.432 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written
2024-05-21 11:24:23.462 | DEBUG    | openadapt.video:write_video_frame:107 - timestamp=1716305063.1059406 video_start_timestamp=1716305047.3683443
2024-05-21 11:24:23.466 | DEBUG    | openadapt.video:write_video_frame:118 - time_diff=15.737596273422241 pts=377 video_stream.average_rate=Fraction(24, 1)
2024-05-21 11:24:23.628 | DEBUG    | __mp_main__:write_events:431 - event_type='screen' written
2024-05-21 11:24:23.628 | INFO     | openadapt.video:finalize_video_writer:157 - flushing video stream...
2024-05-21 11:24:23.797 | INFO     | openadapt.video:close_container:150 - closing video container...
2024-05-21 11:24:23.801 | INFO     | openadapt.video:finalize_video_writer:166 - done
Writing screen(video) events...: 100%|████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 68/68 [00:00<00:00, 123.65event/s]
2024-05-21 11:24:23.801 | INFO     | __mp_main__:write_events:439 - event_type='screen' done
2024-05-21 11:24:23.801 | INFO     | __mp_main__:wrapper_logging:146 -  <- Leave: write_events(None)
OMP: Info #276: omp_set_nested routine deprecated, please use omp_set_max_active_levels instead.
image

@abrichr
Copy link
Contributor

abrichr commented May 29, 2024

@KIRA009 I'm unable to start the recording:

sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) table recording has no column named original_recording_id
[SQL: INSERT INTO recording (timestamp, monitor_width, monitor_height, double_click_interval_seconds, double_click_distance_pixels, platform, task_description, video_start_time, config, original_recording_id) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]
[parameters: (1716994525.9744809, 1512, 982, 0.5, 5.0, 'darwin', 'test', None, '{"ROOT_DIR_PATH": "/Users/abrichr/oa/OpenAdapt/openadapt", "PRIVATE_AI_API_KEY": "******************Y>", "REPLICATE_API_TOKEN": "*******************N ... (1931 characters truncated) ... : "en_core_web_trf", "DASHBOARD_CLIENT_PORT": 5173, "DASHBOARD_SERVER_PORT": 8080, "SOM_SERVER_URL": "<SOM_SERVER_URL>", "DEFAULT_ADAPTER": "openai"}', None)]
(Background on this error at: https://sqlalche.me/e/14/e3q8)


(openadapt-py3.10) abrichr@MacBook-Pro-5 OpenAdapt % cd openadapt
(openadapt-py3.10) abrichr@MacBook-Pro-5 openadapt % alembic upgrade head
DB_URL=sqlite:////Users/abrichr/oa/OpenAdapt/openadapt/data/openadapt.db
INFO  [alembic.runtime.migration] Context impl SQLiteImpl.
INFO  [alembic.runtime.migration] Will assume non-transactional DDL.
(openadapt-py3.10) abrichr@MacBook-Pro-5 openadapt % cd ..
(openadapt-py3.10) abrichr@MacBook-Pro-5 OpenAdapt % python -m openadapt.record test
2024-05-29 10:55:41.647 | INFO     | openadapt.utils:wrapper_logging:1015 -  -> Enter: record(test, None, None, None, False)
2024-05-29 10:55:41.666 | INFO     | openadapt.db.crud:acquire_db_lock:819 - Database is locked. Waiting...
2024-05-29 10:55:42.670 | INFO     | openadapt.db.crud:acquire_db_lock:819 - Database is locked. Waiting...
2024-05-29 10:55:43.678 | INFO     | openadapt.db.crud:acquire_db_lock:819 - Database is locked. Waiting...
2024-05-29 10:55:44.685 | INFO     | openadapt.db.crud:acquire_db_lock:819 - Database is locked. Waiting...
2024-05-29 10:55:45.692 | INFO     | openadapt.db.crud:acquire_db_lock:819 - Database is locked. Waiting...
2024-05-29 10:55:46.697 | INFO     | openadapt.db.crud:acquire_db_lock:819 - Database is locked. Waiting...
2024-05-29 10:55:47.700 | INFO     | openadapt.db.crud:acquire_db_lock:819 - Database is locked. Waiting...
2024-05-29 10:55:48.702 | INFO     | openadapt.db.crud:acquire_db_lock:819 - Database is locked. Waiting...

After manually deleting the lock file:

sqlalchemy.exc.OperationalError: (sqlite3.OperationalError) table recording has no column named original_recording_id
[SQL: INSERT INTO recording (timestamp, monitor_width, monitor_height, double_click_interval_seconds, double_click_distance_pixels, platform, task_description, video_start_time, config, original_recording_id) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]
[parameters: (1716994648.4678552, 1512, 982, 0.5, 5.0, 'darwin', 'test', None, '{"ROOT_DIR_PATH": "/Users/abrichr/oa/OpenAdapt/openadapt", "PRIVATE_AI_API_KEY": "******************Y>", "REPLICATE_API_TOKEN": "*******************N ... (1931 characters truncated) ... : "en_core_web_trf", "DASHBOARD_CLIENT_PORT": 5173, "DASHBOARD_SERVER_PORT": 8080, "SOM_SERVER_URL": "<SOM_SERVER_URL>", "DEFAULT_ADAPTER": "openai"}', None)]
(Background on this error at: https://sqlalche.me/e/14/e3q8)

It looks like there are two issues:

  1. An alembic script is missing from this PR
  2. There is a bug in the database locking logic

@abrichr
Copy link
Contributor

abrichr commented May 29, 2024

After recreating the database, I no longer get the database error. However, I do still get the lock error, and have to manually delete it. Also, after stopping the cording with ctrl+c:

Writing screen(video) events...: 100%|█████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 19/19 [00:00<00:00, 48.83event/s]
2024-05-29 11:05:12.105 | INFO     | __mp_main__:write_events:390 - event_type='screen' done
2024-05-29 11:05:12.106 | INFO     | openadapt.utils:wrapper_logging:1019 -  <- Leave: write_events(None)
OMP: Info #276: omp_set_nested routine deprecated, please use omp_set_max_active_levels instead.
^CTraceback (most recent call last):
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/runpy.py", line 196, in _run_module_as_main
    return _run_code(code, main_globals, None,
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/runpy.py", line 86, in _run_code
    exec(code, run_globals)
  File "/Users/abrichr/oa/OpenAdapt/openadapt/record.py", line 1382, in <module>
    fire.Fire(record)
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/fire/core.py", line 141, in Fire
    component_trace = _Fire(component, args, parsed_flag_args, context, name)
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/fire/core.py", line 466, in _Fire
    component, remaining_args = _CallAndUpdateTrace(
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/fire/core.py", line 681, in _CallAndUpdateTrace
    component = fn(*varargs, **kwargs)
  File "/Users/abrichr/Library/Caches/pypoetry/virtualenvs/openadapt-VBXg4jpm-py3.10/lib/python3.10/site-packages/loguru/_logger.py", line 1226, in catch_wrapper
    return function(*args, **kwargs)
  File "/Users/abrichr/oa/OpenAdapt/openadapt/utils.py", line 1017, in wrapper_logging
    result = func(*args, **kwargs)
  File "/Users/abrichr/oa/OpenAdapt/openadapt/record.py", line 1353, in record
    audio_recorder.join()
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/process.py", line 149, in join
    res = self._popen.wait(timeout)
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/popen_fork.py", line 43, in wait
    return self.poll(os.WNOHANG if timeout == 0.0 else 0)
  File "/usr/local/Cellar/python@3.10/3.10.14/Frameworks/Python.framework/Versions/3.10/lib/python3.10/multiprocessing/popen_fork.py", line 27, in poll
    pid, sts = os.waitpid(self.pid, flag)
KeyboardInterrupt

The terminal appears to hang after this line:

OMP: Info #276: omp_set_nested routine deprecated, please use omp_set_max_active_levels instead.

After a couple of minutes I press ctrl+c again and from the stack trace it appears to be hanging on audio_recorder.join(). If there is something useful happening here we need to log it to the terminal, ideally with tqdm.
image

@abrichr
Copy link
Contributor

abrichr commented May 29, 2024

I think we may need to run this on startup:

        # since the lock is a file, delete it when starting the app so that
        # new instances can start even if the previous one crashed
        crud.release_db_lock(raise_exception=False)

Not sure where to put this.

@KIRA009
Copy link
Contributor Author

KIRA009 commented May 30, 2024

@abrichr I have added a check in acquire_db_lock that checks if the process that previously acquired the lock has ended. 11cc450

@@ -816,8 +817,14 @@ def acquire_db_lock(timeout: int = 60) -> bool:
logger.error("Failed to acquire database lock.")
return False
if os.path.exists(DATA_DIR_PATH / "database.lock"):
logger.info("Database is locked. Waiting...")
time.sleep(1)
with open(DATA_DIR_PATH / "database.lock", "r") as lock_file:
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It appears that this path is re-used in several places. What do you think about defining it in config.py?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Added in 52516e2

@abrichr
Copy link
Contributor

abrichr commented Jun 4, 2024

@KIRA009 we could merge this as-is.

However ideally we would integrate record_audio with record.write_events just like we did with write_video. See write_video in 20e08b8#diff-57d8577d1fb5faaf576a6f5663741c83e672378c13c91a1db036fb7a3f05e067R366, compare with write_video_frame in https://github.com/OpenAdaptAI/OpenAdapt/blob/main/openadapt/video.py#L73

The reason is for the additional instrumentation (performance and logging). What do you think?

Copy link
Contributor

@abrichr abrichr left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Merging to fix the database lock issue ASAP. Thank you @KIRA009 ! 🙏

@abrichr abrichr merged commit 1e11906 into OpenAdaptAI:main Jun 4, 2024
1 check passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants