"MIDISequencer::TickProc called after Auto Stop" keeps on being printed

[goofy2k]

This log is shown when (state.count_in_status & AUTO_STOP_PENDING) is TRUE in MIDISequencer::TickProc (sequencer.cpp).

It is shown for the first time after MEAS 10 BEAT 1 of the recording example and keeps on being displayed endlessly. Here is the log:

GATT procedure initiated: notify; att_handle=16 GUI EVENT: Transport MEAS 9 BEAT 1 E (26718) NICMIDI DRIVER: MIDIOutDriver::OutputMessage GATT procedure initiated: notify; att_handle=16 Entered in MIDIRecorder::Stop() ... E (26718) NICMIDI DRIVER: MIDIOutDriver::OutputMessage GATT procedure initiated: notify; att_handle=16 IN Port MQTT_InGUI EVENT: Transport MEAS 9 BEAT 2 E (27218) NICMIDI DRIVER: MIDIOutDriver::OutputMessage GATT procedure initiated: notify; att_handle=16 closed E (27218) NICMIDI DRIVER: MIDIOutDriver::OutputMessage GATT procedure initiated: notify; att_handle=16 Entered in MIDISequencer::Stop() ...GUI EVENT: Transport MEAS 9 BEAT 3 E (27718) NICMIDI DRIVER: MIDIOutDriver::OutputMessage GATT procedure initiated: notify; att_handle=16 E (27718) NICMIDI DRIVER: MIDIOutDriver::OutputMessage GATT procedure initiated: notify; att_handle=16 GUI EVENT: Transport MEAS 10 GUI EVENT: Transport MEAS 10 BEAT 0 E (28218) NICMIDI DRIVER: MIDIOutDriver::OutputMessage GATT procedure initiated: notify; att_handle=16 E (28218) NICMIDI DRIVER: MIDIOutDriver::OutputMessage GATT procedure initiated: notify; att_handle=16 GUI EVENT: Transport MEAS 10 BEAT 1 MIDISequencer::TickProc called after Auto Stop MIDISequencer::TickProc called after Auto Stop MIDISequencer::TickProc called after Auto Stop MIDISequencer::TickProc called after Auto Stop

[goofy2k]

Of course I could remove the logging line, but I assume that it should be executed only once as it is called on a PENDING auto stop.

[goofy2k]

After some waiting the sequence is interrupted by a triggered task watchdog:

MIDISequencer::TickProc called after Auto Stop MIDISequencer::TickProc called after Auto Stop MIDISequencer::TickProc called after Auto Stop MIDISequencer::TickProc called after Auto Stop MIDISequencer::TickProc called after Auto Stop MIDISequencer::TickProc called after Auto Stop E (26198) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time: E (26198) task_wdt: - IDLE0 (CPU 0) E (26198) task_wdt: Tasks currently running: E (26198) task_wdt: CPU 0: pthread E (26198) task_wdt: CPU 1: IDLE1 E (26198) task_wdt: Print CPU 0 (current core) backtrace

Backtrace:0x400D5FA4:0x3FFBE3B0 0x40084705:0x3FFBE3D0 0x40008544:0x3FFCD510 0x400D6A72:0x3FFCD530 0x4017EB2B:0x3FFCD550 0x400E58A3:0x3FFCD570 0x401A3821:0x3FFCD590 0x4017EA6D:0x3FFCD5B0 0x400D2F88:0x3FFCD5D0 0x40093AB5:0x3FFCD5F0 0x400d5fa4: task_wdt_isr at C:/Users/Fred/esp-idf/components/esp_common/src/task_wdt.c:187

0x40084705: _xt_lowint1 at C:/Users/Fred/esp-idf/components/freertos/xtensa/xtensa_vectors.S:1105

0x400d6a72: usleep at C:/Users/Fred/esp-idf/components/newlib/time.c:341

0x4017eb2b: std::this_thread::__sleep_for(std::chrono::duration<long long, std::ratio<1ll, 1ll> >, std::chrono::duration<long long, std::ratio<1ll, 1000000000ll> >) at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/gcc/libstdc++-v3/src/c++11/thread.cc:204

0x400e58a3: MIDITimer::ThreadProc() at c:\users\fred.espressif\tools\xtensa-esp32-elf\esp-2020r3-8.4.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\8.4.0/thread:382 (inlined by) ?? at c:\users\fred.espressif\tools\xtensa-esp32-elf\esp-2020r3-8.4.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\8.4.0/thread:395 (inlined by) MIDITimer::ThreadProc() at c:\users\fred\esp_projects\midi-sequencer\fckx_sequencer_v27_new_rtmidi_nimbleout\build/../components/NiCMidi/src/timer.cpp:124 0x401a3821: std::thread::_State_impl<std::thread::_Invoker<std::tuple<void ()()> > >::_M_run() at c:\users\fred.espressif\tools\xtensa-esp32-elf\esp-2020r3-8.4.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\8.4.0\bits/invoke.h:60 (inlined by) ?? at c:\users\fred.espressif\tools\xtensa-esp32-elf\esp-2020r3-8.4.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\8.4.0\bits/invoke.h:95 (inlined by) ?? at c:\users\fred.espressif\tools\xtensa-esp32-elf\esp-2020r3-8.4.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\8.4.0/thread:244 (inlined by) ?? at c:\users\fred.espressif\tools\xtensa-esp32-elf\esp-2020r3-8.4.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\8.4.0/thread:253 (inlined by) std::thread::_State_impl<std::thread::_Invoker<std::tuple<void ()()> > >::_M_run() at c:\users\fred.espressif\tools\xtensa-esp32-elf\esp-2020r3-8.4.0\xtensa-esp32-elf\xtensa-esp32-elf\include\c++\8.4.0/thread:196

0x4017ea6d: execute_native_thread_routine at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/gcc/libstdc++-v3/src/c++11/thread.cc:80

0x400d2f88: pthread_task_func at C:/Users/Fred/esp-idf/components/pthread/pthread.c:209 (discriminator 15)

0x40093ab5: vPortTaskWrapper at C:/Users/Fred/esp-idf/components/freertos/xtensa/port.c:143

E (26198) task_wdt: Print CPU 1 backtrace

Backtrace:0x40081EAA:0x3FFIEIB0 ux40084705:0x3FFBE9n0 0:4T0cBPrD:0x3FlBd0a0t0x 0u9oCEtop 0x40081eaa: esp_crosscore_isr at C:/Users/Fred/esp-idf/components/esp32/crosscore_int.c:80

3FFIC0S0 ue4c0D:1T4:0PrFcBca9le0xa0tD61FAu0x3FFBC0C0 0top0DM2D5:0xuFnBe0E: 0T4c0P44cD:0xlFeB 100 0x40093AButox3tFpC12MI Sequencer::TickProc called after Auto Stop MIDISequencer::TickProc called after Auto Stop MIDISequencer::TickProc called after Auto Stop MIDISequencer::TickProc called after Auto Stop MIDISequencer::TickProc called after Auto Stop

[ncassetta]

I apologize, now I have less free time and I can't deal with NiCMidi much. I found that not even the last commit is conclusive because it introduces other errors and I can't get rid of them

[goofy2k]

OK, Nicola. I will keep that in mind.

I'll keep on reporting my findings. Don't expect you jump in immediately ;-)

Op wo 29 dec. 2021 07:31 schreef Nicola Cassetta @.***>:

I apologize, now I have less free time and I can't deal with NiCMidi much. I found that not even the last commit is conclusive because it introduces other errors and I can't get rid of them

— Reply to this email directly, view it on GitHub https://github.com/ncassetta/NiCMidi/issues/7#issuecomment-1002418344, or unsubscribe https://github.com/notifications/unsubscribe-auth/AGII3TU3TZVXK4XWV4VMTSDUTKTMVANCNFSM5KZJBZFQ . You are receiving this because you authored the thread.Message ID: @.***>

[ncassetta]

In the end I think I succeeded. I just posted another commit which should fix a lot of errors (I hope all of them :-)). Playing should work, let me know if there are any problems in the recording. (I missed a line and committed two times. The last is Solved issue #5 )

[goofy2k]

OK , I'm going to have a look . And let you know my findings! I also had a close look to Output port instantiation and opening . It came to late for the moment that the first messages had to be sent. Hopefully everything becomes clearer with this and with your improvements.

Op wo 29 dec. 2021 14:50 schreef Nicola Cassetta @.***>:

In the end I think I succeeded. I just posted another commit which should fix a lot of errors (I hope all of them :-)). Playing should work, let me know if there are any problems in the recording. (I missed a line and committed two times. The last is Solved issue #5 https://github.com/ncassetta/NiCMidi/issues/5 )

— Reply to this email directly, view it on GitHub https://github.com/ncassetta/NiCMidi/issues/7#issuecomment-1002603529, or unsubscribe https://github.com/notifications/unsubscribe-auth/AGII3TRB64ZMTJHY63BML5DUTMGY7ANCNFSM5KZJBZFQ . You are receiving this because you authored the thread.Message ID: @.***>

[goofy2k]

Great ! Things come together at the right moment! I will freeze this as v28.

I managed to get the synth connected BEFORE any message are sent by the sequencer. And your today's commit makes that the sequencer example runs smoothly. At least: in the first cycle.... I created a loop with trk.Clear() in some places to prevent inserting notes over and over again. Starting with the second cycle there are some hick-ups. Maybe you can have a look at my version of the sequencer example to what may be the cause.

Note that I use conditional compilation to deselect the drums part.

TEST_SEQUENCER2_cpp.txt

I will now also test recording.

[EDIT] in subsequent runs the program stops/hangs after the first cycle, giving a "Auto stopping the sequencer: StaticStopProc called at time 2378". I did not apply changes. I will analyze this....

[goofy2k]

Recording behaves very irregular / still unpredictable. One time I heard the recorded notes being played back. Not always sequencing / recording stops. Sometimes the program hangs in the Stop procedure.

More analysis / observation necessary.

[ncassetta]

In the sequencer example you forgot to rewind the sequencer with GoToZero() after the second time the sequencer plays.

[goofy2k]

It doesn't solve the issue when I do that.

I assume that it would be good to put GoToZero() just before Play() every time?

[goofy2k]

The behaviour is very odd. I places GoToZero() before the two calls of Play()

1) when the second cycle is running the sequence of notes plays slower and with irregular timing. 2) after some cycles the output stops after giving "Auto stopping the sequencer: StaticStopProc called at time nnnn)" . In that state, the program responds properly to e.g. messages over the MQTTT Midi In port. 3) The most odd: for testing I tried to put a while(true) loop around playing the 3 tracks (actually 2 because DRUMS are off) like this:

#define PLAYSECOND
#ifdef PLAYSECOND

while (true) {   
    cout << "Playing 3 tracks ..." << endl;
    sequencer.GoToZero();
    sequencer.Play();
    while (sequencer.IsPlaying())
        MIDITimer::Wait(50);
    cout << "    Stop Playing 3 tracks" << endl;

} //while true

#endif //PLAYSECOND

When I do this, this code is never reached ! The program hangs with a message like under 2) after playing the final note of the first Play().

This is some work to do for me....

[EDIT] This interaction is not there. It is just the interaction with the end of the sequence. Has nothing to do with changes in other parts of the code. Apparently the last part in the MIDISequencer::StaticTickProc causes the problem (?) The strange part is that sometimes this does not happen at the end of the first sequence.....

[ncassetta]

I don't have this behaviour, I tried to put a loop in the same point and it went well. I suspect that your problem could be again in the drivers: are your opening and closing functions blocking (i.e. they return only when the port is ready to send or receive data)? They could send orders to the driver to open or close and then return without waiting it to finish. Since Start() calls MIDIDriver::OpenPort() and Stop() calls MIDIDriver::ClosePort() a quick execution of Stop() and Start() could bring trouble. I suggest these: 1) Again, try to put a pause (with MIDITimer::Wait()) between the end of a play and the start of the subsequent. 2) Place a MIDIDriver::OpenOutPorts() at the beginning of the program (and assure the port is ready before playing) and a MIDIDriver::CloseOutPorts() at the end: this prevents Start and Stop to open and close the port continuosly (in fact, the hardware ports are opened only the first time the OpenPort() method is called, if you call it twice it only remembers the number of times the ports were opened). You should see the log Out Port XXX open 2 times. If this solves the problem, it depends by your port driver

[goofy2k]

Thanks. Yes, I certainly do not rule out the influence of my drivers. Their status is pretty "immature". Thanks for your suggestions. I'll let you know the progress...

Op do 30 dec. 2021 21:43 schreef Nicola Cassetta @.***>:

I don't have this behaviour, I tried to put a loop in the same point and it went well. I suspect that your problem could be again in the drivers: are your opening and closing functions blocking (i.e. they return only when the port is ready to send or receive data)? They could send orders to the driver to open or close and then return without waiting it to finish. Since Start() calls MIDIDriver::OpenPort() and Stop() calls MIDIDriver::ClosePort() a quick execution of Stop() and Start() could bring trouble. I suggest these:

1. Again, try to put a pause (with MIDITimer::Wait()) between the end of a play and the start of the subsequent.
2. Place a MIDIDriver::OpenOutPorts() at the beginning of the program (and assure the port is ready before playing) and a MIDIDriver::CloseOutPorts() at the end: this prevents Start and Stop to open and close the port continuosly (in fact, the hardware ports are opened only the first time the OpenPort() method is called, if you call it twice it only remembers the number of times the ports were opened). You should see the log Out Port XXX open 2 times.

— Reply to this email directly, view it on GitHub https://github.com/ncassetta/NiCMidi/issues/7#issuecomment-1003175547, or unsubscribe https://github.com/notifications/unsubscribe-auth/AGII3TSMUNHHJ6DSGRNFCMLUTS75XANCNFSM5KZJBZFQ . You are receiving this because you authored the thread.Message ID: @.***>

[goofy2k]

SEQUENCER: The end of play is simply never reached. The line with DEBUG 6 does not produce output. Instead of this, I see "Auto stopping the sequencer: StaticStopProc called at time nnnn" . See attached runtime dump.

RECORDER and SEQUENCER v29 runtime.txt

code: // now we can play track 1 only cout << "Playing track 1 ..." << endl; sequencer.GoToZero(); sequencer.Play(); ESP_LOGE(TAG," DEBUG 5 "); while (sequencer.IsPlaying()) { MIDITimer::Wait(50); }; ESP_LOGE(TAG," DEBUG 6 "); cout << "The sequencer finished" << endl;

RECORDER: here the code contains a Stop() call. Two types of behaviour: complete neglect of the stop or hangs somewhat later. Code here, runtime dumps in attachment.

recorder.Start();
std::cout << "Recorder started\n";

MIDITimer::Wait(15000);                 // Waits 15 secs: play something to record (remember to match
                                        // the input channel with the one set in SetTrackRecChannel)
std::cout << "Calling recorder.Stop()\n";
recorder.Stop();
std::cout << "Recorder stopped\n";
MIDITimer::Wait(5000); 
std::cout << "Proceeding with next steps\n";
sequencer.GoToZero();                   // rewinds
sequencer.Start();
std::cout << "Now the sequencer plays what you have recorded\n";

while (sequencer.IsPlaying())         // waits until the sequencer finishes
    MIDITimer::Wait(50);

[ncassetta]

@goofy2k 1) In test_recorder2.cpp I forgot to put the usual while (sequencer.IsPlaying()) MIDITimer::Wait(50); at the end, so program exits suddenly when the sequencer starts playing

2) The MIDIManager::AllNotesOff() come from manager.cpp:186. They are normal, before closing a port the the driver must send a CC ALL_NOTES_OFF message for every channel in the port

3) I don't get the crashes, and suspect the trouble is caused by opening and closing routines. I notice now that in the last post I made a mistake: you should try to put MIDIManager::OpenOutPorts()

at the beginning of test_advancedsequencer_noinput (and the corresponding MIDIManager::CloseOutPorts(); at the end). If you get trouble try to put a pause after the instruction with MIDITimer::Wait().

In the recorder example you must call also MIDIManager::OpenInPorts() and MIDIManager::CloseInPorts()

This , as I said above, prevents Start() and Stop() to open and close the ports continuosly.

[goofy2k]

OK , I'll study this.

In the mean time I have been busy implementing more message types on my synth. It can now handle control messages for setting e.g. ADSR and lfo depth/frequency. I used code based on your thru example. Had to change channel comparisons from -1 to 255 to let all channels through.

I'll send my findings on the above sequencer / recorder things later.

Op ma 3 jan. 2022 13:54 schreef Nicola Cassetta @.***>:

@goofy2k https://github.com/goofy2k

1.

In test_recorder2.cpp I forgot to put the usual while (sequencer.IsPlaying()) MIDITimer::Wait(50); at the end, so program exits suddenly when the sequencer starts playing 2.

The MIDIManager::AllNotesOff() come from manager.cpp:186. They are normal, before closing a port the the driver must send a CC ALL_NOTES_OFF message for every channel in the port 3.

I don't get the crashes, and suspect the trouble is caused by opening and closing routines. I notice now that in the last post I made a mistake: you should try to put MIDIManager::OpenOutPorts()

at the beginning of test_advancedsequencer_noinput (and the corresponding MIDIManager::CloseOutPorts(); at the end). If you get trouble try to put a pause after the instruction with MIDITimer::Wait().

In the recorder example you must call also MIDIManager::OpenInPorts() and MIDIManager::CloseInPorts()

This , as I said above, prevents Start() and Stop() to open and close the ports continuosly.

— Reply to this email directly, view it on GitHub https://github.com/ncassetta/NiCMidi/issues/7#issuecomment-1004071338, or unsubscribe https://github.com/notifications/unsubscribe-auth/AGII3TWRGVWYZ3KOPKI7HC3UUGL7NANCNFSM5KZJBZFQ . You are receiving this because you were mentioned.Message ID: @.***>

[goofy2k]

I have added the suggested MIDIManager::OpenOutPorts(). And tested the recorder example again. In the recording phase I hear the entered notes playing. When MIDIrecorder::Stop() is called it does not lead to a stop. I added logs to the MIDIrecorder::Stop() routine for tracing. The trace continues until seq->MIDISequencer::Stop() is called. So, I also added logs to this routine. There, the trace stops until proc_lock.lock() is called. After this, the sequencer keeps on running........ I enclose the runtime log and the relevant parts of the MIDIrecorder::Stop() and MIDISequencer::Stop(). (CORRECTION: I will add the complete recorder.cpp and sequencer.cpp as the files may contain other changes.)

The behaviour of the sequencer example has slightly improved. The different versions are played more often, but in the end the program hangs at the same location: "Auto stopping the sequencer: StaticStopProc called at time nnnn"

recorder runtime 220103.txt

recorder_cpp.txt

sequencer_cpp.txt

[goofy2k]

I think that I have to understand some things better:

1. the meaning of the various types of lock/unlock procedures used
2. the precise meaning of "open" and "close" for IO ports
3. possible interactions between conditions for 1. and 2.

As I have implemented the port opening and closing routines myself, the actual status after calling them may be different of what is normally expected.

[ncassetta]

From your log I see that your procedure is very slow: in my computer it begins at Meas 6 Beat 1 and terminates before beat 2. Can you test the library with a computer? I used for development Windows 10 with the GS Wavetable synth (at least for MIDI out). I examined also your cpp files and they are identical (except for logs) to those of the library. 1) Meaning of lock/unlock: all the MIDITickComponent objects have a TickProc() which is called by the manager every 10 msecs. This is done by mean of a parallel thread. Moreover the sequencer auto stop launches (with detach) a third thread which expires after the stop. So the proc_lock mutex is needed to get thread safe behaviour: the TickProc locks and releases the mutex and also the methods of the main thread, so they cannot interfere. You can try to comment the lock - unlock in Stop() to see what happens (at least you should see the various logs mixed together). However, in your tracing the Stop() hangs at the proc_lock.lock() line, but this is very strange because the TickProc continues to be executed (and so to lock and release the mutex) and hence the Stop() should not remain locked. I found this: https://en.cppreference.com/w/cpp/thread/thread/hardware_concurrency: try to see if your system supports three concurrent threads. 2) Open/close I remember that old MIDI devices cannot accept more than a connection at a time, so if an application used the MIDI port no other app could interact with it. So in NiCMidi I opened the ports at the beginning of the playing and closed them at the end. The MIDIDriver routines are intended to return only when the port is ready to send or receive MIDI data, so be careful in your driver routines. My suggestion to open the ports at the start avoids opening/closing in Start/Stop: you can comment the lines which open and close the ports there and you should not see any change.

[ncassetta]

A desperate try could be this: 1) include the header timer.h 2) at the beginning call MIDITimer::Start() and at the end MIDITimer::Stop() 3) substitute the line sequencer.cpp:1418 std::thread(StaticStopProc, this).detach(); with Stop();

This prevent the third thread to be launched at auto stop, while the thread which calls TickProc is always active because you start the timer at the beginning and stop it at the end, simplifying the thread start/join/detach structure. However it consumes more CPU time because two threads are always active.

[goofy2k]

What do you mean with "procedure" in "procedure is very slow"? What is the actual process / status that is finished/reached before beat 2? I don't have access to my synth via Windows. Also don't have a Windows C++ compiler other than the command line ESP-IDF that is intended to deliver firmware to ESP32 boards and alike.

Re 1. There are probably more "threads" running in my code. Certainly those for the low level processes for the IO ports that run in the background. This involves WIFI (for MQTT/for MIDI in) and nimBLE (for MIDI out). ESP-IDF uses the freeRTOS OS that contains a system of mutexes, timers, semaphores etc. There may be interaction between my "system" threads and the NiCMidi threads. I have to learn and see if and how these different ways of treating "simultaneous" processes can coexist.

Re 2. I Interpreted "open" as "having the actual connection" with a peer, rather than "having all conditions ready for making the connection". I set a connected_ flag once a connection is detected. This is done by a OnConnect callback in the nimBLE lib. I have the impression (but can be wrong) that I wait for this real connection before doing anything with your lib that depends on availability of this connection.

My closeInPort (if this is the right name....) does nothing other than setting the connected_ flag to false. I'll have to check if I only close the Ports when NiCMidi does not depend on them. Your suggestions will help me to do that.

One other option is to distribute tasks differently over the two CPU's of the board. So many parameters :-(

But I'll give this a try!

There is also a command for listing the existing threads/processes and their status. I'll see if I can get some info out of this.

[goofy2k]

I can't open the link in your message. Perhaps a typo?

Op wo 5 jan. 2022 21:52 schreef Nicola Cassetta @.***>:

From your log I see that your procedure is very slow: in my computer it begins at Meas 6 Beat 1 and terminates before beat 2. Can you test the library with a computer? I used for development Windows 10 with the GS Wavetable synth (at least for MIDI out). I examined also your cpp files and they are identical (except for logs) to those of the library.

1. Meaning of lock/unlock: all the MIDITickComponent objects have a TickProc() which is called by the manager every 10 msecs. This is done by mean of a parallel thread. Moreover the sequencer auto stop launches (with detach) a third thread which expires after the stop. So the proc_lock mutex is needed to get thread safe behaviour: the TickProc locks and releases the mutex and also the methods of the main thread, so they cannot interfere. You can try to comment the lock - unlock in Stop() to see what happens (at least you should see the various logs mixed together). However, in your tracing the Stop() hangs at the proc_lock.lock() line, but this is very strange because the TickProc continues to be executed (and so to lock and release the mutex) and hence the Stop() should not remain locked. I found this: https://en.cppreference.com/w/cpp/thread/thread/hardware_concurrency http://url: try to see if your system supports three concurrent threads.
2. Open/close I remember that old MIDI devices cannot accept more than a connection at a time, so if an application used the MIDI port no other app could interact with it. So in NiCMidi I opened the ports at the beginning of the playing and closed them at the end. The MIDIDriver routines are intended to return only when the port is ready to send or receive MIDI data, so be careful in your driver routines. My suggestion to open the ports at the start avoids opening/closing in Start/Stop: you can comment the lines which open and close the ports there and you should not see any change.

— Reply to this email directly, view it on GitHub https://github.com/ncassetta/NiCMidi/issues/7#issuecomment-1006068063, or unsubscribe https://github.com/notifications/unsubscribe-auth/AGII3TSJ7TLSWASIOUIZN5LUUSVPNANCNFSM5KZJBZFQ . You are receiving this because you were mentioned.Message ID: @.***>

[EDIT]: found the page. Tried to use the code but it does not work for me: /src/c++11/thread.cc:177: undefined reference to `sysconf'.

I'll try to get it going, or learn about nr of threads specifically for ESP-IDF

[ncassetta]

This is my log of test_recorder2.cpp on Windows 10

. . . . . .

GUI EVENT: Transport MEAS 5 BEAT 3 MIDIOutDriver::OutputMessage MIDIOutDriver::OutputMessage GUI EVENT: Transport MEAS 6 GUI EVENT: Transport MEAS 6 BEAT 0 MIDIOutDriver::OutputMessage MIDIOutDriver::OutputMessage GUI EVENT: Transport MEAS 6 BEAT 1 Entered in MIDIRecorder::Stop() ... IN Port LoopBe Internal MIDI 0 closed Entered in MIDISequencer::Stop() ... Timer stopped by MIDITimer::Stop() OUT Port Microsoft GS Wavetable Synth 0 closed OUT Port LoopBe Internal MIDI 1 closed GUI EVENT: Transport SEQUENCER STOP ... Exiting from MIDISequencer::Stop() GUI EVENT: All GENERAL RESET GUI EVENT: All GENERAL RESET GUI EVENT: All GENERAL RESET ... Exiting from MIDIRecorder::Stop() Recorder stopped GUI EVENT: All GENERAL RESET GUI EVENT: All GENERAL RESET Now the sequencer plays what you have recorded Sequencer stopped MIDIManager Exit()

Process returned 0 (0x0) execution time : 33.130 s Press any key to continue.

In my computer the MIDIRecorder::Stop() is called after MEAS 6 BEAT 1 and it stops the recorder and the sequencer before MEAS 6 BEAT 2

[goofy2k]

In my app I have some waits. Maybe that is the reason for the long running period.

I have been experimenting with various settings. Observed differences in behaviour.... In the end found a combination where playing the recordings is reached. Certainly not yet flawless, but this may contain leads! I will summarize and let you know.

Op do 6 jan. 2022 12:31 schreef Nicola Cassetta @.***>:

This is my log of test_recorder2.cpp on Windows 10

. . . . . .

GUI EVENT: Transport MEAS 5 BEAT 3 MIDIOutDriver::OutputMessage MIDIOutDriver::OutputMessage GUI EVENT: Transport MEAS 6 GUI EVENT: Transport MEAS 6 BEAT 0 MIDIOutDriver::OutputMessage MIDIOutDriver::OutputMessage GUI EVENT: Transport MEAS 6 BEAT 1 Entered in MIDIRecorder::Stop() ... IN Port LoopBe Internal MIDI 0 closed Entered in MIDISequencer::Stop() ... Timer stopped by MIDITimer::Stop() OUT Port Microsoft GS Wavetable Synth 0 closed OUT Port LoopBe Internal MIDI 1 closed GUI EVENT: Transport SEQUENCER STOP ... Exiting from MIDISequencer::Stop() GUI EVENT: All GENERAL RESET GUI EVENT: All GENERAL RESET GUI EVENT: All GENERAL RESET ... Exiting from MIDIRecorder::Stop() Recorder stopped GUI EVENT: All GENERAL RESET GUI EVENT: All GENERAL RESET Now the sequencer plays what you have recorded Sequencer stopped MIDIManager Exit()

Process returned 0 (0x0) execution time : 33.130 s Press any key to continue.

In my computer the MIDIRecorder::Stop() is called after MEAS 6 BEAT 1 and it stops the recorder and the sequencer before MEAS 6 BEAT 2

— Reply to this email directly, view it on GitHub https://github.com/ncassetta/NiCMidi/issues/7#issuecomment-1006502650, or unsubscribe https://github.com/notifications/unsubscribe-auth/AGII3TTSJOYHAVCMI6BDXRTUUV4QTANCNFSM5KZJBZFQ . You are receiving this because you were mentioned.Message ID: @.***>

[goofy2k]

Two files here: one with overview of settings and the result per experiment with the recorder example. The other file contains the runtime output.

At least I now have settings (nr 8.) where notes are played after the recording has stopped! The playing of the recording is not error free.

The question is now if settings nr.8 is a good start for next steps, or that we have to think of new settings based on the observations

I will do a check how the sequencer example performs with the same settings.

SUMMARY recorder exps 220106 .txt

runtime logs 220106.txt

[goofy2k]

With the settings of expt 8., the sequencer example displays " Auto stopping the sequencer: StaticStopProc called at time xxxx" and then crashes with:

Auto stopping the sequencer: StaticStopProc called at time 2376

abort() was called at PC 0x4016a13b on core 0 0x4016a13b: cxxabiv1::terminate(void (*)()) at /builds/idf/crosstool-NG/.build/HOST-x86_64-w64-mingw32/xtensa-esp32-elf/src/gcc/libstdc++-v3/libsupc++/eh_terminate.cc:47

When the Stop() is reverted back to std::thread(StaticStopProc, this).detach(); the program either:

• hangs after displaying "Auto stopping..." at the end of first time playing. No crash.
• OR It plays for the second time and the crashes at the end of that in AdvancedSequencer::Stop() at GoToMeasure(state.cur_measure, state.cur_beat); (advancedsequencer.cpp:628)

[ncassetta]

Have you started the timer at the beginning? The timer must be opened already two times (one by your MIDITimer::Start() and one by Sequencer::Start() ) otherwise Sequencer::Stop() tries to close it terminating its same thread, which gives a deadlock.

Another experiment you can do is to lower the timer resolution. Default resolution is 10 msecs. With MIDITimer::SetResolution (before the timer is opened) you can try to have less calls to the TickProc and less CPU time.

[goofy2k]

• I will do a check on your suggestions.

  • Q: what do you mean with "Have you started the timer at the beginning?". In my app_main I do NOT explicitly start the timer, but I call recorder.Start() and sequencer.Start(). I assume that the start of the timer(s) is handled by these lib calls. Right? But I can do a check on this in the relevant code, because it may contain changes. Here is my main code for the recorder example: TEST_RECORDING 220107_cpp.txt

• I also added some conditional compiler MACROS . This helps me to switch more easily between the various options

• I will pay more attention to reproducibility. I noticed that some behavior is not stable. E.g. with all settings default, the sequencer sometimes runs to the end many times without an error. Only sometimes it shows an error.

It is probably helpful to FIRST focus on stability of the sequencer example. When that is achieved switch to the more complicated recorder example. What is your opinion on this?

[goofy2k]

Some success! I needed that......

I have been testing the TEST_ADVANCEDSEQUENCER_NOINPUT example repeatedly and saw two types of behavior. One completing the example successfully, the other with crash around Stopping the sequencer.

In the ESP-IDF menuconfig tool there is a group of settings for PThreads. These are:

(5) Default task priority (3072) Default task stack size (768) Minimum allowed pthread stack size Default pthread core affinity (Core 1) ---> (pthread) Default name of pthreads

The default pthread affinity was originally set to "No affinity". When I change this to CORE 1, the sequencer example runs OK! When I set it to CORE0, the behaviour is poor in all cases that I have seen up to now. Note that these tests are all with the currently defaults for in you code.

I will set this to CORE 1 from now on and see what this brings for the recorder example Note that the WiFi and MQTT functionality are attached to CORE 0.

[ncassetta]

When you call MIDITimer::Start () (in timer.cpp) the first time it creates the parallel thread which in turn calls the TickProc of all queued MIDITickComponent objects. If you call it again, it just increments the num_open counter to remember how many times it has been opened. Conversely, MIDITimer::Stop() decrements num_open and joins the thread only when it reaches 0. So, if you start the timer at the beginning, you simplify the work in MIDISequencer::Start() and Stop(): they call MIDITimer::Open() and Close(), but these don't create (or join) any thread. Auto stop requires a third thread because it originates by the sequencer TickProc (in the parallel thread) and calls MIDISequencer::Stop() (which in turn calls MIDITimer::Stop(): so the thread may try to close itself causing a deadlock). So replacing the line I indicated with Stop() surely causes a crash if you don't open the timer at the beginning.

[goofy2k]

I do not quite understand if I now have to add something.

"....replacing the line I indicated with Stop() surely causes a crash". Do you mean std::thread(StaticStopProc, this).detach() in sequencer.cpp:1418? By default I now use the line with std::thread in it.

Anyway I will place two additional logs in MIDITimer::Start () and MIDITimer::Stop () that report the status of the counter, also when num_open takes other values than 0 or 1.

[ncassetta]

No, if you use the original line you don't need to open the timer at the beginning. However you can try it as experiment, because, as I said, it lightens the work of MIDISequencer::Start() and MIDISequencer::Stop() preventing them creating and joining the timer thread.

[goofy2k]

I see 2 times a timer start before the recording phase. And 2 times a stop after the recording phase.

num_open follows the sequence: starts 0 > 1 > 2 .... recording .....stops 2 > 1 hangs before showing 0 No playing ..

So: the second timer stop does not exit. It looks like the second bg_thread.join() does not finish OK. The file contains 2 full logs. One withou and one without entering notes.

RECORDER v30 RUNTIME.txt

The strange thing is that I have heard some recorded notes before. Now the playing part is not reached.

[ncassetta]

Yes, one is for the recorder and one for the sequencer. But the thread is started only when num_open = 1, the second time only num_open is incremented. And the thread is joined only at the last stop

[goofy2k]

I found this: https://docs.espressif.com/projects/esp-idf/en/latest/esp32/api-reference/system/pthread.html

Now studying it...

There are some examples: https://github.com/espressif/esp-idf/tree/397639d/examples/system/pthread https://github.com/espressif/esp-idf/tree/397639d/examples/cxx/pthread

I think that. specifically for ESP32, I am going to add one or two equivalents of your code based on these examples...

[EDIT]

• This does not bring me anything new. The last action that I see is entering of the if (num_open == 0) codeblock. The program does not return from bg_thread.join(). The log with "MIDITimer::Stop exit with num_open: 0" never shows up.
• I have two logs in the ThreadProc (see file). This is to detect if the proc is actually executed.

After entering Stop for the second time num_open equals 1 , I see the log inside the if block stops reporting. But it is not clear that the ThreadProc in fact is not executed as the log outside the if block NEVER reports. I do not understand that.

CODE WITH LOGS IN ThreadProc 220108.txt (link text adapted)

RUNTIME LOG 220108.txt

• I ran a test with the thru example. thru.Start(), MidiTimer::Wait for 5 secs then thru.Stop(). This starts from num_open == 1 , reports on num_open==0 and returns. See log file:

RUNTIME THRU 220108.txt

{EDIT2] A misstake! there is no if block in ThreadProc. It is a WHILE block. The first log should be called only once! (correct?). I added an additional log AFTER the while block. This is indeed the case !

The strange thing is that the "not returning from the last bg_thread.join() " only takes place in the recorder example. The thru and sequencer examples don't show this error.

While analyzing the differences beween the three, you can see that thru doesn't stop flawless always too:

RECORD_SEQUENCE_TRHU.txt

For this one there is a link with btController (bluetooth). I will point my arrows to that area.......

[goofy2k]

Sometimes THRU also shows an error at creation of the bg_tread....

[goofy2k]

BREAKTHRU :-) :-) I have set the timer resolution to 50 ms. As suggested by you some messages ago. Now I can record notes and play them back !

[goofy2k]

I'll probably have to find out how to balance the occupation of the CPU cores to reduce the timer resolution again.

Now and than the stop hangs again! It looks like that decreasing the timer resolution decreases the chance on getting the error, but does not prevent it.

[goofy2k]

So, it looks like the code is still unstable.

I now think of trying to use freeRTOS to implement timing. ESP-IDF makes use of this lib a lot and usage of threads is in fact discouraged. I have used freeRTOS functionality before (my synth firmware contains a metronome that uses it).

This will mean "patching" of timer.cpp. I aim to create a timer, dedicated for ESP32, with the same interface as the current timer. In this sense it is good for me to know where I can expect interactions in other parts of your lib. I hope that you can point me to those.

One of them may be code that deals with Autostop????

[EDIT]: making progress with this! THRU and SEQUENCER properly playing. Need to implement proper Stop() based on num_open before I can test recording.

[ncassetta]

I did now a commit in the branch bug_correction, which limits the threads to two, with no join/detach. You could try this

[goofy2k]

OK. I'll test that. Give me some time. In the meantime I am making good progress using a freeRTOS timer. All three examples run smoothly! I am currently adding conditional compilation flags for easy switching to ESP32 systems. After that I'll test your commit.

Op di 11 jan. 2022 17:34 schreef Nicola Cassetta @.***>:

I did now a commit in the branch bug_correction, which limits the threads to two, with no join/detach. You could try this

— Reply to this email directly, view it on GitHub https://github.com/ncassetta/NiCMidi/issues/7#issuecomment-1010146257, or unsubscribe https://github.com/notifications/unsubscribe-auth/AGII3TSB35LE6FBOPVDWQPLUVRL3DANCNFSM5KZJBZFQ . You are receiving this because you were mentioned.Message ID: @.***>

[goofy2k]

• My solution works fine for the timer stability problem on ESP32 / ESP-IDF. I added a conditional compilation flag ESP32_TIMER to timer.cpp/.h When this is un-defined, the "original" code is active. Note that the "original" code is not exactly the same as yours, primarily because of added logs. It is available under v31 in my repo.

• More improvements are probably possible / required, but this is now a good anchor point. For ESP32 it is probably useful to become fully independent of std::chrono but this doesn't have a high priority I think.

• I will absorb your new commit in v32 and test the performance with the ESP32_TIMER condition defined and undefined.

[goofy2k]

OK, I tested your commit. It does not solve the issue that I had. Especially in the sequencer example I see the earlier error after the final stop.

BUT: you commit does not disturb the ESP32_TIMER patch. This keeps on being stable. So I will keep BOTH and have the ESP32_TIMER condition defined for my system. If I'm correct, this only has implications for the timer.cpp/.h files.

Can you explain shortly what is the purpose of the Autostop feature?

[ncassetta]

The autostop calls the sequencer Stop() when it reaches the end of the MIDI song, stopping the sequencer. It is activated by the if in sequencer.cpp:1413. It controls: 1) if we are at the end of the song (GetNextEventTime() returns false, so there aren't other events after now time) 2) if we must not jump to a previous measure (it could be if the loop play is activated and we are at the last measure, see the 1st if) 3) if the flag play_mode is set to PLAY_BOUNDED. Originally the autostop was always active, but I had to allow it to be deactivated for recording (when recording the sequencer must be stopped manually). If the sequencer must auto stop the line 1420 starts a (detached) third thread which only calls MIDISequencer::Stop() and terminates. In the master branch the autostop cannot directly call Stop(), because it in turn calls MIDITimer::Stop() which could try to join its same thread, causing a deadlock, so a third thread is needed. In the other commit the timer is never stopped, so the autostop can call Stop() in the same thread.