fix audio desync for realsies, stderr to log.txt

src/imgui/window/animation_preview.cpp

@@ -1,9 +1,11 @@
 #include "animation_preview.hpp"
 
 #include <algorithm>
+#include <cmath>
 #include <chrono>
 #include <filesystem>
 #include <format>
+#include <map>
 #include <optional>
 #include <ranges>
 #include <system_error>
@@ -82,6 +84,51 @@ namespace anm2ed::imgui
       directory.clear();
       frames.clear();
     }
+
+    bool render_audio_stream_generate(AudioStream& audioStream, std::map<int, anm2::Sound>& sounds,
+                                      const std::vector<int>& frameSoundIDs, int fps)
+    {
+      audioStream.stream.clear();
+      if (frameSoundIDs.empty() || fps <= 0) return true;
+
+      SDL_AudioSpec mixSpec = audioStream.spec;
+      mixSpec.format = SDL_AUDIO_F32;
+      auto* mixer = MIX_CreateMixer(&mixSpec);
+      if (!mixer) return false;
+
+      auto channels = std::max(mixSpec.channels, 1);
+      auto sampleRate = std::max(mixSpec.freq, 1);
+      auto framesPerStep = (double)sampleRate / (double)fps;
+      auto sampleFrameAccumulator = 0.0;
+      auto frameBuffer = std::vector<float>{};
+
+      for (auto soundID : frameSoundIDs)
+      {
+        if (soundID != -1 && sounds.contains(soundID)) sounds.at(soundID).audio.play(false, mixer);
+
+        sampleFrameAccumulator += framesPerStep;
+        auto sampleFramesToGenerate = (int)std::floor(sampleFrameAccumulator);
+        sampleFramesToGenerate = std::max(sampleFramesToGenerate, 1);
+        sampleFrameAccumulator -= (double)sampleFramesToGenerate;
+
+        frameBuffer.resize((std::size_t)sampleFramesToGenerate * (std::size_t)channels);
+        if (!MIX_Generate(mixer, frameBuffer.data(), (int)(frameBuffer.size() * sizeof(float))))
+        {
+          for (auto& [_, sound] : sounds)
+            sound.audio.track_detach(mixer);
+          MIX_DestroyMixer(mixer);
+          audioStream.stream.clear();
+          return false;
+        }
+
+        audioStream.stream.insert(audioStream.stream.end(), frameBuffer.begin(), frameBuffer.end());
+      }
+
+      for (auto& [_, sound] : sounds)
+        sound.audio.track_detach(mixer);
+      MIX_DestroyMixer(mixer);
+      return true;
+    }
   }
 
   AnimationPreview::AnimationPreview() : Canvas(vec2()) {}
@@ -106,6 +153,8 @@ namespace anm2ed::imgui
 
       if (playback.time > end || playback.isFinished)
       {
+        if (settings.timelineIsSound) audioStream.capture_end(mixer);
+
         if (type == render::PNGS)
         {
           if (!renderTempFrames.empty())
@@ -185,7 +234,20 @@ namespace anm2ed::imgui
         }
         else
         {
-          if (animation_render(ffmpegPath, path, renderTempFrames, audioStream, (render::Type)type, anm2.info.fps))
+          if (settings.timelineIsSound && type != render::GIF)
+          {
+            if (!render_audio_stream_generate(audioStream, anm2.content.sounds, renderFrameSoundIDs, anm2.info.fps))
+            {
+              toasts.push(localize.get(TOAST_EXPORT_RENDERED_ANIMATION_FAILED));
+              logger.error("Failed to generate deterministic render audio stream; exporting without audio.");
+              audioStream.stream.clear();
+            }
+          }
+          else
+            audioStream.stream.clear();
+
+          if (animation_render(ffmpegPath, path, renderTempFrames, renderTempFrameDurations, audioStream,
+                               (render::Type)type, anm2.info.fps))
           {
             toasts.push(std::vformat(localize.get(TOAST_EXPORT_RENDERED_ANIMATION), std::make_format_args(pathString)));
             logger.info(std::vformat(localize.get(TOAST_EXPORT_RENDERED_ANIMATION, anm2ed::ENGLISH),
@@ -204,9 +266,15 @@ namespace anm2ed::imgui
         {
           renderTempDirectory.clear();
           renderTempFrames.clear();
+          renderTempFrameDurations.clear();
+          renderFrameSoundIDs.clear();
         }
         else
+        {
           render_temp_cleanup(renderTempDirectory, renderTempFrames);
+          renderTempFrameDurations.clear();
+          renderFrameSoundIDs.clear();
+        }
 
         if (settings.renderIsRawAnimation)
         {
@@ -220,8 +288,6 @@ namespace anm2ed::imgui
           isCheckerPanInitialized = false;
         }
 
-        if (settings.timelineIsSound) audioStream.capture_end(mixer);
-
         playback.isPlaying = false;
         playback.isFinished = false;
         manager.isRecording = false;
@@ -229,6 +295,28 @@ namespace anm2ed::imgui
       }
       else
       {
+        if (settings.timelineIsSound && renderTempFrames.empty()) audioStream.capture_begin(mixer);
+        auto frameSoundID = -1;
+        if (settings.timelineIsSound && !anm2.content.sounds.empty())
+        {
+          if (auto animation = document.animation_get();
+              animation && animation->triggers.isVisible && (!settings.timelineIsOnlyShowLayers || manager.isRecording))
+          {
+            if (auto trigger = animation->triggers.frame_generate(playback.time, anm2::TRIGGER); trigger.isVisible)
+            {
+              if (!trigger.soundIDs.empty())
+              {
+                auto soundIndex = trigger.soundIDs.size() > 1
+                                      ? (size_t)math::random_in_range(0.0f, (float)trigger.soundIDs.size())
+                                      : (size_t)0;
+                soundIndex = std::min(soundIndex, trigger.soundIDs.size() - 1);
+                auto soundID = trigger.soundIDs[soundIndex];
+                if (anm2.content.sounds.contains(soundID)) frameSoundID = soundID;
+              }
+            }
+          }
+        }
+        renderFrameSoundIDs.push_back(frameSoundID);
 
         bind();
         auto pixels = pixels_get();
@@ -237,6 +325,24 @@ namespace anm2ed::imgui
         if (Texture::write_pixels_png(framePath, size, pixels.data()))
         {
           renderTempFrames.push_back(framePath);
+          auto nowCounter = SDL_GetPerformanceCounter();
+          auto counterFrequency = SDL_GetPerformanceFrequency();
+          auto fallbackDuration = 1.0 / (double)std::max(anm2.info.fps, 1);
+
+          if (renderTempFrames.size() == 1)
+          {
+            renderCaptureCounterPrev = nowCounter;
+            renderTempFrameDurations.push_back(fallbackDuration);
+          }
+          else
+          {
+            auto elapsedCounter = nowCounter - renderCaptureCounterPrev;
+            auto frameDuration = counterFrequency > 0 ? (double)elapsedCounter / (double)counterFrequency : 0.0;
+            frameDuration = std::max(frameDuration, 1.0 / 1000.0);
+            renderTempFrameDurations.back() = frameDuration;
+            renderTempFrameDurations.push_back(frameDuration);
+            renderCaptureCounterPrev = nowCounter;
+          }
         }
         else
         {
@@ -244,6 +350,8 @@ namespace anm2ed::imgui
           logger.error(std::vformat(localize.get(TOAST_EXPORT_RENDERED_ANIMATION_FAILED, anm2ed::ENGLISH),
                                     std::make_format_args(pathString)));
           if (type != render::PNGS) render_temp_cleanup(renderTempDirectory, renderTempFrames);
+          renderTempFrameDurations.clear();
+          renderFrameSoundIDs.clear();
           playback.isPlaying = false;
           playback.isFinished = false;
           manager.isRecording = false;
@@ -258,7 +366,7 @@ namespace anm2ed::imgui
       auto& isSound = settings.timelineIsSound;
       auto& isOnlyShowLayers = settings.timelineIsOnlyShowLayers;
 
-      if (!anm2.content.sounds.empty() && isSound)
+      if (!manager.isRecording && !anm2.content.sounds.empty() && isSound)
       {
         if (auto animation = document.animation_get();
             animation && animation->triggers.isVisible && (!isOnlyShowLayers || manager.isRecording))
@@ -474,8 +582,6 @@ namespace anm2ed::imgui
       {
         savedSettings = settings;
 
-        if (settings.timelineIsSound) audioStream.capture_begin(mixer);
-
         if (settings.renderIsRawAnimation)
         {
           settings.previewBackgroundColor = vec4();
@@ -502,6 +608,9 @@ namespace anm2ed::imgui
         manager.isRecordingStart = false;
         manager.isRecording = true;
         renderTempFrames.clear();
+        renderTempFrameDurations.clear();
+        renderFrameSoundIDs.clear();
+        renderCaptureCounterPrev = 0;
         if (settings.renderType == render::PNGS)
         {
           renderTempDirectory = settings.renderPath;
@@ -1033,9 +1142,13 @@ namespace anm2ed::imgui
         {
           renderTempDirectory.clear();
           renderTempFrames.clear();
+          renderTempFrameDurations.clear();
         }
         else
+        {
           render_temp_cleanup(renderTempDirectory, renderTempFrames);
+          renderTempFrameDurations.clear();
+        }
 
         pan = savedPan;
         zoom = savedZoom;

src/imgui/window/animation_preview.hpp

@@ -30,6 +30,9 @@ namespace anm2ed::imgui
     glm::vec2 moveOffset{};
     std::filesystem::path renderTempDirectory{};
     std::vector<std::filesystem::path> renderTempFrames{};
+    std::vector<double> renderTempFrameDurations{};
+    std::vector<int> renderFrameSoundIDs{};
+    Uint64 renderCaptureCounterPrev{};
 
   public:
     AnimationPreview();

src/log.cpp

@@ -1,16 +1,26 @@
 #include "log.hpp"
 
+#include <array>
 #include <print>
 
+#include "path_.hpp"
 #include "sdl.hpp"
 #include "time_.hpp"
 
+#if _WIN32
+  #include <fcntl.h>
+  #include <io.h>
+#else
+  #include <unistd.h>
+#endif
+
 using namespace anm2ed::util;
 
 namespace anm2ed
 {
   void Logger::write_raw(const std::string& message)
   {
+    std::lock_guard lock(mutex);
     std::println("{}", message);
     if (file.is_open()) file << message << '\n' << std::flush;
   }
@@ -26,7 +36,105 @@ namespace anm2ed
   void Logger::error(const std::string& message) { write(ERROR, message); }
   void Logger::fatal(const std::string& message) { write(FATAL, message); }
   void Logger::command(const std::string& message) { write(COMMAND, message); }
-  void Logger::open(const std::filesystem::path& path) { file.open(path, std::ios::out | std::ios::app); }
+
+  void Logger::stderr_pump()
+  {
+    std::string pending{};
+    std::array<char, 512> buffer{};
+    while (isStderrRedirecting)
+    {
+      int readBytes{};
+#if _WIN32
+      readBytes = _read(stderrPipeReadFd, buffer.data(), (unsigned int)buffer.size());
+#else
+      readBytes = (int)read(stderrPipeReadFd, buffer.data(), buffer.size());
+#endif
+      if (readBytes <= 0) break;
+
+      pending.append(buffer.data(), (std::size_t)readBytes);
+
+      std::size_t lineEnd{};
+      while ((lineEnd = pending.find('\n')) != std::string::npos)
+      {
+        auto line = pending.substr(0, lineEnd);
+        if (!line.empty() && line.back() == '\r') line.pop_back();
+        if (!line.empty()) write_raw(line);
+        pending.erase(0, lineEnd + 1);
+      }
+    }
+
+    if (!pending.empty()) write_raw(pending);
+  }
+
+  void Logger::stderr_redirect_start()
+  {
+    if (isStderrRedirecting) return;
+
+    int pipeFds[2]{-1, -1};
+#if _WIN32
+    if (_pipe(pipeFds, 4096, _O_BINARY) != 0) return;
+    stderrOriginalFd = _dup(_fileno(stderr));
+    if (stderrOriginalFd < 0 || _dup2(pipeFds[1], _fileno(stderr)) != 0)
+    {
+      _close(pipeFds[0]);
+      _close(pipeFds[1]);
+      return;
+    }
+    _close(pipeFds[1]);
+#else
+    if (pipe(pipeFds) != 0) return;
+    stderrOriginalFd = dup(fileno(stderr));
+    if (stderrOriginalFd < 0 || dup2(pipeFds[1], fileno(stderr)) < 0)
+    {
+      close(pipeFds[0]);
+      close(pipeFds[1]);
+      return;
+    }
+    close(pipeFds[1]);
+#endif
+
+    std::setvbuf(stderr, nullptr, _IONBF, 0);
+
+    stderrPipeReadFd = pipeFds[0];
+    isStderrRedirecting = true;
+    stderrThread = std::thread([this]() { stderr_pump(); });
+  }
+
+  void Logger::stderr_redirect_stop()
+  {
+    if (!isStderrRedirecting) return;
+    isStderrRedirecting = false;
+
+    if (stderrOriginalFd >= 0)
+    {
+#if _WIN32
+      _dup2(stderrOriginalFd, _fileno(stderr));
+      _close(stderrOriginalFd);
+#else
+      dup2(stderrOriginalFd, fileno(stderr));
+      close(stderrOriginalFd);
+#endif
+      stderrOriginalFd = -1;
+    }
+
+    if (stderrPipeReadFd >= 0)
+    {
+#if _WIN32
+      _close(stderrPipeReadFd);
+#else
+      close(stderrPipeReadFd);
+#endif
+      stderrPipeReadFd = -1;
+    }
+
+    if (stderrThread.joinable()) stderrThread.join();
+  }
+
+  void Logger::open(const std::filesystem::path& path)
+  {
+    file.open(path, std::ios::out | std::ios::app);
+    stderr_redirect_start();
+  }
 
   std::filesystem::path Logger::path() { return sdl::preferences_directory_get() / "log.txt"; }
 
@@ -39,6 +147,7 @@ namespace anm2ed
   Logger::~Logger()
   {
     info("Exiting Anm2Ed");
+    stderr_redirect_stop();
     if (file.is_open()) file.close();
   }
 }

src/log.hpp

@@ -4,6 +4,8 @@
 #include <fstream>
 #include <string>
 #include <string_view>
+#include <mutex>
+#include <thread>
 
 namespace anm2ed
 {
@@ -44,6 +46,16 @@ namespace anm2ed
   class Logger
   {
     std::ofstream file{};
+    std::mutex mutex{};
+    std::thread stderrThread{};
+    bool isStderrRedirecting{};
+    int stderrPipeReadFd{-1};
+    int stderrPipeWriteFd{-1};
+    int stderrOriginalFd{-1};
+
+    void stderr_redirect_start();
+    void stderr_redirect_stop();
+    void stderr_pump();
 
   public:
     static std::filesystem::path path();

src/render.cpp

@@ -35,10 +35,11 @@ namespace anm2ed
   }
 
   bool animation_render(const std::filesystem::path& ffmpegPath, const std::filesystem::path& path,
-                        const std::vector<std::filesystem::path>& framePaths, AudioStream& audioStream,
-                        render::Type type, int fps)
+                        const std::vector<std::filesystem::path>& framePaths,
+                        const std::vector<double>& frameDurations, AudioStream& audioStream, render::Type type, int fps)
   {
     if (framePaths.empty() || ffmpegPath.empty() || path.empty()) return false;
+    (void)frameDurations;
     fps = std::max(fps, 1);
 
     auto pathString = path::to_utf8(path);
@@ -83,8 +84,16 @@ namespace anm2ed
         audioFile.write(data, byteCount);
         audioFile.close();
 
-        audioInputArguments = std::format("-f f32le -ar {0} -ac {1} -i \"{2}\"", audioStream.spec.freq,
-                                          audioStream.spec.channels, path::to_utf8(audioPath));
+        auto sampleRate = std::max(audioStream.spec.freq, 1);
+        auto channels = std::max(audioStream.spec.channels, 1);
+        auto audioDurationFilter = std::string{};
+        auto frameCount = (double)std::max((int)framePaths.size(), 1);
+        auto expectedDurationSeconds = frameCount / (double)fps;
+        if (expectedDurationSeconds > 0.0)
+          audioDurationFilter += std::format("apad,atrim=duration={:.9f}", expectedDurationSeconds);
+
+        audioInputArguments =
+            std::format("-f f32le -ar {0} -ac {1} -i \"{2}\"", sampleRate, channels, path::to_utf8(audioPath));
 
         switch (type)
         {
@@ -97,6 +106,9 @@ namespace anm2ed
           default:
             break;
         }
+
+        if (!audioDurationFilter.empty())
+          audioOutputArguments = std::format("-af \"{}\" {}", audioDurationFilter, audioOutputArguments);
       }
       else
       {
@@ -114,10 +126,12 @@ namespace anm2ed
       return false;
     }
 
-    auto frameDuration = 1.0 / (double)fps;
-    for (const auto& framePath : framePaths)
+    auto defaultFrameDuration = 1.0 / (double)fps;
+    for (std::size_t index = 0; index < framePaths.size(); ++index)
     {
+      auto framePath = framePaths[index];
       auto framePathString = path::to_utf8(framePath);
+      auto frameDuration = defaultFrameDuration;
       framesListFile << "file '" << ffmpeg_concat_escape(framePathString) << "'\n";
       framesListFile << "duration " << std::format("{:.9f}", frameDuration) << "\n";
     }
@@ -127,9 +141,9 @@ namespace anm2ed
 
     auto framesListPathString = path::to_utf8(framesListPath);
     command = std::format("\"{0}\" -y -f concat -safe 0 -i \"{1}\"", ffmpegPathString, framesListPathString);
-    command += std::format(" -fps_mode cfr -r {}", fps);
 
     if (!audioInputArguments.empty()) command += " " + audioInputArguments;
+    command += std::format(" -fps_mode cfr -r {}", fps);
 
     switch (type)
     {

src/render.hpp

@@ -37,5 +37,6 @@ namespace anm2ed
 {
   std::filesystem::path ffmpeg_log_path();
   bool animation_render(const std::filesystem::path&, const std::filesystem::path&,
-                        const std::vector<std::filesystem::path>&, AudioStream&, render::Type, int);
+                        const std::vector<std::filesystem::path>&, const std::vector<double>&, AudioStream&,
+                        render::Type, int);
 }

src/resource/audio.cpp

@@ -117,6 +117,14 @@ namespace anm2ed::resource
     MIX_StopTrack(track, 0);
   }
 
+  void Audio::track_detach(MIX_Mixer* mixer)
+  {
+    if (!track) return;
+    if (mixer && MIX_GetTrackMixer(track) != mixer) return;
+    MIX_DestroyTrack(track);
+    track = nullptr;
+  }
+
   bool Audio::is_playing() const { return track && MIX_TrackPlaying(track); }
 
   Audio::Audio(const Audio& other)

src/resource/audio.hpp

@@ -28,6 +28,7 @@ namespace anm2ed::resource
     bool is_valid();
     void play(bool loop = false, MIX_Mixer* = nullptr);
     void stop(MIX_Mixer* = nullptr);
+    void track_detach(MIX_Mixer* = nullptr);
     bool is_playing() const;
   };
 }

src/resource/audio_stream.cpp

@@ -1,5 +1,7 @@
 #include "audio_stream.hpp"
 
+#include <algorithm>
+
 #if defined(__clang__) || defined(__GNUC__)
   #pragma GCC diagnostic push
   #pragma GCC diagnostic ignored "-Wunused-parameter"
@@ -10,16 +12,46 @@ namespace anm2ed
   void AudioStream::callback(void* userData, MIX_Mixer* mixer, const SDL_AudioSpec* spec, float* pcm, int samples)
   {
     auto self = (AudioStream*)userData;
+    if (!self->isFirstCallbackCaptured)
+    {
+      self->firstCallbackCounter = SDL_GetPerformanceCounter();
+      self->isFirstCallbackCaptured = true;
+    }
+    self->callbackSamples = samples;
     self->stream.insert(self->stream.end(), pcm, pcm + samples);
   }
 
   AudioStream::AudioStream(MIX_Mixer* mixer) { MIX_GetMixerFormat(mixer, &spec); }
 
-  void AudioStream::capture_begin(MIX_Mixer* mixer) { MIX_SetPostMixCallback(mixer, callback, this); }
+  void AudioStream::capture_begin(MIX_Mixer* mixer)
+  {
+    stream.clear();
+    callbackSamples = 0;
+    captureStartCounter = SDL_GetPerformanceCounter();
+    firstCallbackCounter = 0;
+    isFirstCallbackCaptured = false;
+    MIX_SetPostMixCallback(mixer, callback, this);
+  }
 
   void AudioStream::capture_end(MIX_Mixer* mixer)
   {
     MIX_SetPostMixCallback(mixer, nullptr, this);
     stream.clear();
   }
-}
+
+  double AudioStream::callback_latency_seconds_get() const
+  {
+    auto freq = std::max(spec.freq, 1);
+    auto channels = std::max(spec.channels, 1);
+    auto framesPerCallback = (double)callbackSamples / (double)channels;
+    return framesPerCallback / (double)freq;
+  }
+
+  double AudioStream::capture_start_delay_seconds_get() const
+  {
+    if (!isFirstCallbackCaptured || captureStartCounter == 0 || firstCallbackCounter < captureStartCounter) return 0.0;
+    auto frequency = SDL_GetPerformanceFrequency();
+    if (frequency == 0) return 0.0;
+    return (double)(firstCallbackCounter - captureStartCounter) / (double)frequency;
+  }
+}

src/resource/audio_stream.hpp

@@ -12,9 +12,15 @@ namespace anm2ed
   public:
     std::vector<float> stream{};
     SDL_AudioSpec spec{};
+    int callbackSamples{};
+    Uint64 captureStartCounter{};
+    Uint64 firstCallbackCounter{};
+    bool isFirstCallbackCaptured{};
 
     AudioStream(MIX_Mixer*);
     void capture_begin(MIX_Mixer*);
     void capture_end(MIX_Mixer*);
+    double callback_latency_seconds_get() const;
+    double capture_start_delay_seconds_get() const;
   };
-}
+}

src/state.cpp

@@ -159,6 +159,31 @@ namespace anm2ed
   {
     auto currentTick = SDL_GetTicks();
     auto currentUpdate = SDL_GetTicks();
+    auto isRecording = manager.isRecording;
+    auto tickIntervalMs = (double)TICK_INTERVAL;
+
+    if (isRecording)
+    {
+      if (auto document = manager.get())
+      {
+        auto fps = std::max(document->anm2.info.fps, 1);
+        tickIntervalMs = std::max(1.0, 1000.0 / (double)fps);
+      }
+    }
+
+    if (isRecording != wasRecording)
+    {
+      // Drop any accumulated backlog when entering/leaving recording mode.
+      tickAccumulatorMs = 0.0;
+      previousTick = currentTick;
+      wasRecording = isRecording;
+    }
+
+    if (previousTick == 0) previousTick = currentTick;
+    auto tickDeltaMs = currentTick - previousTick;
+    tickDeltaMs = std::min<Uint64>(tickDeltaMs, 250);
+    tickAccumulatorMs += (double)tickDeltaMs;
+    previousTick = currentTick;
 
     if (currentUpdate - previousUpdate >= UPDATE_INTERVAL)
     {
@@ -167,10 +192,10 @@ namespace anm2ed
       previousUpdate = currentUpdate;
     }
 
-    if (currentTick - previousTick >= TICK_INTERVAL)
+    if (tickAccumulatorMs >= tickIntervalMs)
     {
       tick(settings);
-      previousTick = currentTick;
+      tickAccumulatorMs -= tickIntervalMs;
     }
 
     SDL_Delay(1);

src/state.hpp

@@ -26,6 +26,8 @@ namespace anm2ed
 
     uint64_t previousTick{};
     uint64_t previousUpdate{};
+    double tickAccumulatorMs{};
+    bool wasRecording{};
 
     State(SDL_Window*&, Settings& settings, std::vector<std::string>&);