Audio narration - Githubissues

KIRA009 commented 1 month ago

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

[x] My code follows the style guidelines of OpenAdapt
[x] I have performed a self-review of my code
[ ] If applicable, I have added tests to prove my fix is functional/effective
[x] 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)
[x] New and existing unit tests pass locally with my changes

How can your code be run and tested?

Other information

abrichr commented 1 month ago

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.

Any suggestions?

KIRA009 commented 1 month ago

@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 commented 1 month ago

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 commented 1 month ago

@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 commented 1 month ago

@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.

abrichr commented 1 month ago

@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:

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

abrichr commented 1 month ago

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.

abrichr commented 1 month ago

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 commented 1 month ago

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

abrichr commented 1 month ago

@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 https://github.com/OpenAdaptAI/OpenAdapt/commit/20e08b8ac7d4f2c5f23d37839e7f9ef522427f90#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?

OpenAdaptAI / OpenAdapt

Audio narration #673