Various updates to the rnp edl handling

Main change is to rewrite the start/stop event handling to do fewer
passes and use simpler logic (it no longer has to track durations).

The temporary work audio codec is switched to flac; slightly lower hard
drive use and it avoids the 4-hour length limit of wav.

Some improvements to the video seeking when processing deskshare and
webcam videos, to avoid video dropouts.

Tweaks to the audio encoding quality settings.

Remove an unused function.

record-and-playback/core/lib/recordandplayback/edl.rb

@@ -22,8 +22,9 @@ require File.expand_path('../edl/audio', __FILE__)
 
 module BigBlueButton
   module EDL
-    FFMPEG = ['ffmpeg', '-y', '-v', 'warning', '-nostats']
+    # max_error_rate is set to ignore errors in poorly encoded webcams/deskshare
-    FFPROBE = ['ffprobe', '-v', 'warning', '-print_format', 'json', '-show_format', '-show_streams', '-count_frames']
+    FFMPEG = ['ffmpeg', '-y', '-v', 'warning', '-nostats', '-max_error_rate', '1.0']
+    FFPROBE = ['ffprobe', '-v', 'warning', '-print_format', 'json', '-show_format', '-show_streams']
 
     def self.encode(audio, video, format, output_basename, audio_offset = 0)
       output = "#{output_basename}.#{format[:extension]}"

record-and-playback/core/lib/recordandplayback/edl/audio.rb

@@ -22,9 +22,9 @@ module BigBlueButton
     module Audio
       FFMPEG_AEVALSRC = "aevalsrc=s=48000:c=stereo:exprs=0|0"
       FFMPEG_AFORMAT = "aformat=sample_fmts=s16:sample_rates=48000:channel_layouts=stereo"
-      FFMPEG_WF_CODEC = 'pcm_s16le'
+      FFMPEG_WF_CODEC = 'flac'
-      FFMPEG_WF_ARGS = ['-c:a', FFMPEG_WF_CODEC, '-f', 'wav']
+      FFMPEG_WF_ARGS = ['-c:a', FFMPEG_WF_CODEC, '-f', 'flac']
-      WF_EXT = 'wav'
+      WF_EXT = 'flac'
 
       def self.dump(edl)
         BigBlueButton.logger.debug "EDL Dump:"
@@ -97,7 +97,10 @@ module BigBlueButton
 
             filter = "[#{input_index}] "
 
-            if entry[:original_duration] and ((entry[:original_duration] - audioinfo[audio[:filename]][:duration]).to_f / entry[:original_duration]).abs < 0.05
+            if entry[:original_duration] and
+                 (audioinfo[audio[:filename]][:duration].to_f / entry[:original_duration]) < 0.999 and
+                 ((entry[:original_duration] - audioinfo[audio[:filename]][:duration]).to_f /
+                        entry[:original_duration]).abs < 0.05
               speed = audioinfo[audio[:filename]][:duration].to_f / entry[:original_duration]
               BigBlueButton.logger.warn "  Audio file length mismatch, adjusting speed to #{speed}"
 
@@ -182,6 +185,7 @@ module BigBlueButton
           if info[:format][:format_name] == 'wav'
             # wav files generated by freeswitch can have incorrect length
             # field if longer than 4GB, so recalculate based on filesize (ouch!)
+            BigBlueButton.logger.debug("Recalculated duration from wav file length")
             audio_size = info[:format][:size].to_r - 44 # wav header is 44 bytes
             info[:duration] = (audio_size * 8 / info[:audio][:bit_rate].to_i * 1000).to_i
           else

record-and-playback/core/lib/recordandplayback/edl/video.rb

@@ -190,7 +190,7 @@ module BigBlueButton
           info = video_info(videofile)
           BigBlueButton.logger.debug "    width: #{info[:width]}, height: #{info[:height]}, duration: #{info[:duration]}"
 
-          if !info[:video] || !info[:video][:nb_read_frames]
+          if !info[:video]
             BigBlueButton.logger.warn "    This video file is corrupt! It will be removed from the output."
             corrupt_videos << videofile
           end
@@ -385,12 +385,27 @@ module BigBlueButton
             BigBlueButton.logger.debug "      offset: left: #{offset_x}, top: #{offset_y}"
 
             BigBlueButton.logger.debug "      start timestamp: #{video[:timestamp]}"
+            BigBlueButton.logger.debug("      codec: #{videoinfo[video[:filename]][:video][:codec_name].inspect}")
+
+            if videoinfo[video[:filename]][:video][:codec_name] == "flashsv2"
+              # Desktop sharing videos in flashsv2 do not have regular
+              # keyframes, so seeking in them doesn't really work.
+              # To make processing more reliable, always decode them from the
+              # start in each cut.
+              seek = 0
+            else
+              # Webcam videos are variable, low fps; it might be that there's
+              # no frame until some time after the seek point. Start decoding
+              # 30s before the desired point to avoid this issue.
+              seek = video[:timestamp] - 30000
+              seek = 0 if seek < 0
+            end
 
             ffmpeg_inputs << {
               :filename => video[:filename],
-              :seek => video[:timestamp]
+              :seek => seek
             }
-            ffmpeg_filter << "[in#{index}]; [#{index}]fps=24,scale=#{scale_width}:#{scale_height}"
+            ffmpeg_filter << "[in#{index}]; [#{index}]fps=24,trim=start=#{ms_to_s(video[:timestamp])},setpts=PTS-STARTPTS,scale=#{scale_width}:#{scale_height}"
             if layout_area[:pad]
               ffmpeg_filter << ",pad=w=#{tile_width}:h=#{tile_height}:x=#{offset_x}:y=#{offset_y}:color=white"
               offset_x = 0
@@ -411,7 +426,7 @@ module BigBlueButton
 
         ffmpeg_cmd = [*FFMPEG]
         ffmpeg_inputs.each do |input|
-          ffmpeg_cmd += ['-ss', ms_to_s(input[:seek]), '-i', input[:filename]]
+          ffmpeg_cmd += ['-ss', ms_to_s(input[:seek]), '-itsoffset', ms_to_s(input[:seek]), '-i', input[:filename]]
         end
         ffmpeg_cmd += ['-filter_complex', ffmpeg_filter, *FFMPEG_WF_ARGS, '-']
 

record-and-playback/core/lib/recordandplayback/generators/audio_processor.rb

@@ -32,6 +32,11 @@ module BigBlueButton
     #
     def self.process(archive_dir, file_basename)
       audio_edl = BigBlueButton::AudioEvents.create_audio_edl(archive_dir)
+      BigBlueButton::EDL::Audio.dump(audio_edl)
+
+      BigBlueButton.logger.info("Applying recording start stop events:")
+      audio_edl = BigBlueButton::Events.edl_match_recording_marks_audio(audio_edl, archive_dir)
+      BigBlueButton::EDL::Audio.dump(audio_edl)
 
       audio_dir = "#{archive_dir}/audio"
       events_xml = "#{archive_dir}/events.xml"
@@ -40,13 +45,13 @@ module BigBlueButton
 
       ogg_format = {
         :extension => 'ogg',
-        :parameters => [ [ '-c:a', 'libvorbis', '-b:a', '48K', '-f', 'ogg' ] ]
+        :parameters => [ [ '-c:a', 'libvorbis', '-q:a', '2', '-f', 'ogg' ] ]
       }
       BigBlueButton::EDL.encode(wav_file, nil, ogg_format, file_basename)
 
       webm_format = {
         :extension => 'webm',
-        :parameters => [ [ '-c:a', 'libvorbis', '-b:a', '48K', '-f', 'webm' ] ],
+        :parameters => [ [ '-c:a', 'libvorbis', '-q:a', '2', '-f', 'webm' ] ],
         :postprocess => [ [ 'mkclean', '--quiet', ':input', ':output' ] ]
       }
       BigBlueButton::EDL.encode(wav_file, nil, webm_format, file_basename)

record-and-playback/core/lib/recordandplayback/generators/events.rb

@@ -270,125 +270,127 @@ module BigBlueButton
     end
 
     def self.edl_match_recording_marks_audio(edl, archive_dir)
-      calculate_entry_files_timestamp = Proc.new do |edl_entry, offset|
+      edl_entry_offset = Proc.new do |edl_entry, offset|
-        edl_entry[:audio][:timestamp] += offset if edl_entry[:audio]
+        new_entry = { :audio => nil }
+        if edl_entry[:audio]
+          new_entry[:audio] = {
+            :filename => edl_entry[:audio][:filename],
+            :timestamp => edl_entry[:audio][:timestamp] + offset
+          }
+        end
+        if edl_entry[:original_duration]
+          new_entry[:original_duration] = edl_entry[:original_duration]
+        end
+        new_entry
       end
-
+      edl_empty_entry = Proc.new do
-      empty_entry = {
+        { :audio => nil }
-        :timestamp => nil,
+      end
-        :audio => nil
+      return BigBlueButton::Events.edl_match_recording_marks(edl, archive_dir,
-      }
+                      edl_entry_offset, edl_empty_entry)
-
-      return edl_match_recording_marks(edl, archive_dir, calculate_entry_files_timestamp, empty_entry)
     end
 
     def self.edl_match_recording_marks_video(edl, archive_dir)
-      calculate_entry_files_timestamp = Proc.new do |edl_entry, offset|
+      edl_entry_offset = Proc.new do |edl_entry, offset|
-        if edl_entry[:areas][:webcam]
+        new_entry = { :areas => {} }
-          edl_entry[:areas][:webcam].each do |webcam_entry|
+        edl_entry[:areas].each do |area, videos|
-            webcam_entry[:timestamp] += offset
+          new_entry[:areas][area] = []
-          end
+          videos.each do |video|
-        end
+            new_entry[:areas][area] << {
-        if edl_entry[:areas][:deskshare]
+              :filename => video[:filename],
-          edl_entry[:areas][:deskshare].each do |deskshare_entry|
+              :timestamp => video[:timestamp] + offset
-            deskshare_entry[:timestamp] += offset
+            }
           end
         end
+        new_entry
       end
-
+      edl_empty_entry = Proc.new do
-      empty_entry = {
+        { :areas => {} }
-        :timestamp => nil,
+      end
-        :areas => { :webcam => [], :deskshare => [] }
+      return BigBlueButton::Events.edl_match_recording_marks(edl, archive_dir,
-      }
+                      edl_entry_offset, edl_empty_entry)
-
-      return edl_match_recording_marks(edl, archive_dir, calculate_entry_files_timestamp, empty_entry)
     end
 
-    def self.edl_match_recording_marks_deskshare(edl, archive_dir)
+    def self.get_start_stop_events_for_edl(archive_dir)
-      calculate_entry_files_timestamp = Proc.new do |edl_entry, offset|
+      initial_timestamp = BigBlueButton::Events.first_event_timestamp(
-        edl_entry[:areas][:deskshare].each do |webcam_entry|
+              "#{archive_dir}/events.xml")
-          webcam_entry[:timestamp] += offset
+      start_stop_events = BigBlueButton::Events.match_start_and_stop_rec_events(
-        end
+              BigBlueButton::Events.get_start_and_stop_rec_events(
-      end
+                     "#{archive_dir}/events.xml"))
-
-      empty_entry = {
-        :timestamp => nil,
-        :areas => { :deskshare => [] }
-      }
-
-      return edl_match_recording_marks(edl, archive_dir, calculate_entry_files_timestamp, empty_entry)
-    end
-
-    def self.edl_match_recording_marks(edl, archive_dir, calculate_entry_files_timestamp, empty_entry)
-      events = Nokogiri::XML(File.open("#{archive_dir}/events.xml"))
-      event = events.at_xpath('/recording/event[position()=1]')
-      initial_timestamp = event['timestamp'].to_i
-
-      start_stop_events = BigBlueButton::Events.match_start_and_stop_rec_events(BigBlueButton::Events.get_start_and_stop_rec_events("#{archive_dir}/events.xml"))
-      # translated the timestamps to the recording timestamp
       start_stop_events.each do |record_event|
         record_event[:start_timestamp] -= initial_timestamp
         record_event[:stop_timestamp] -= initial_timestamp
       end
-      BigBlueButton.logger.debug "start_stop_events:\n#{BigBlueButton.hash_to_str(start_stop_events)}"
+      return start_stop_events
+    end
 
-      # add duration to EDL
+    def self.edl_match_recording_marks(edl, archive_dir, edl_entry_offset, edl_empty_entry)
-      edl.each_with_index do |edl_entry, i|
+      start_stop_events = BigBlueButton::Events.get_start_stop_events_for_edl(archive_dir)
-        if i == edl.length-1
+
-          edl_entry[:duration] = 0
+      last_stop_timestamp = 0
-        else
+      offset = 0
-          edl_entry[:duration] = edl[i+1][:timestamp] - edl_entry[:timestamp]
+
+      new_edl = [ edl_empty_entry.call ]
+
+      # Do a sanity check on the values
+      if edl.first[:timestamp] > start_stop_events.first[:start_timestamp]
+        raise "Recording start event is before first EDL entry"
+      end
+      if edl.last[:timestamp] < start_stop_events.last[:stop_timestamp]
+        raise "Recording stop event is after last EDL entry"
+      end
+
+      output_i = 0
+
+      # Loop over all the recorded intervals to build the new edl
+      start_stop_events.each do |start_stop_event|
+        BigBlueButton.logger.debug("Recording interval: #{start_stop_event[:start_timestamp]} to #{start_stop_event[:stop_timestamp]}")
+        offset += start_stop_event[:start_timestamp] - last_stop_timestamp
+        BigBlueButton.logger.debug("Offset is now #{offset}")
+
+        input_i = 0
+
+        # Find the last EDL event from before or at the recording start
+        loop do
+          break if edl[input_i+1][:timestamp] > start_stop_event[:start_timestamp]
+          input_i += 1
         end
-      end
 
-      BigBlueButton.logger.debug "edl with duration:\n#{BigBlueButton.hash_to_str(edl)}"
+        BigBlueButton.logger.debug("Found last event prior to recording start:")
+        BigBlueButton.logger.debug(BigBlueButton.hash_to_str(edl[input_i]))
 
-      edl_postprocessed = []
+        # Add the first event, trimming the start as needed.
-      start_stop_events.each do |record_event|
+        initial_trim = start_stop_event[:start_timestamp] - edl[input_i][:timestamp]
-        edl.each do |edl_entry|
+        BigBlueButton.logger.debug("Have to trim #{initial_trim}")
-          edl_copy = Marshal.load(Marshal.dump(edl_entry))
+        new_edl[output_i] = edl_entry_offset.call(edl[input_i], initial_trim)
+        new_edl[output_i][:timestamp] = start_stop_event[:start_timestamp] - offset
+        BigBlueButton.logger.debug("New event at recording start:")
+        BigBlueButton.logger.debug(BigBlueButton.hash_to_str(new_edl[output_i]))
+        output_i += 1
 
-          edl_start = edl_entry[:timestamp]
+        # Add the intervening events up to the stop
-          edl_stop = edl_entry[:timestamp] + edl_entry[:duration]
+        loop do
-          rec_start = record_event[:start_timestamp]
+          input_i += 1
-          rec_stop = record_event[:stop_timestamp]
+          break if edl[input_i][:timestamp] >= start_stop_event[:stop_timestamp]
 
-          # edl doesn't match with the recording marks
+          new_edl[output_i] = edl_entry_offset.call(edl[input_i], 0)
-          if (edl_start < rec_start and edl_stop < rec_start) or (edl_start > rec_stop and edl_stop > rec_stop)
+          new_edl[output_i][:timestamp] = edl[input_i][:timestamp] - offset
-            next
-          end
 
-          # adjust the beginning timestamp
+          output_i += 1
-          if edl_start < rec_start
-            edl_copy[:timestamp] = rec_start
-            edl_copy[:duration] -= rec_start - edl_start
-            calculate_entry_files_timestamp.call(edl_copy, rec_start - edl_start)
-            # edl_copy[:audio][:timestamp] = rec_start - edl_start
-          end
-
-          # adjust the duration
-          if edl_stop > rec_stop
-            edl_copy[:duration] -= edl_stop - rec_stop
-          end
-
-          edl_postprocessed << edl_copy
         end
+
+        # Add a terminating event at the stop timestamp
+        new_edl[output_i] = edl_empty_entry.call
+        new_edl[output_i][:timestamp] = start_stop_event[:stop_timestamp] - offset
+
+        # Note that output_i isn't incremented here
+        # In the next loop iteration, the terminating entry will be replaced
+        # with the next video start.
+
+        last_stop_timestamp = start_stop_event[:stop_timestamp]
       end
 
-      # trim the intervals
+      return new_edl
-      next_timestamp = 0
-      edl_postprocessed.each do |edl_entry|
-        edl_entry[:timestamp] = next_timestamp
-        next_timestamp += edl_entry[:duration]
-      end
-      empty_entry[:timestamp] = next_timestamp
-      edl_postprocessed << empty_entry
-#      edl_postprocessed << {
-#        :timestamp => next_timestamp,
-#        media_symbol => nil
-#      }
-      BigBlueButton.logger.debug "edl_postprocessed:\n#{BigBlueButton.hash_to_str(edl_postprocessed)}"
-      return edl_postprocessed
     end
 
     def self.linkify( text )
@@ -454,6 +456,60 @@ module BigBlueButton
       duration
     end
 
+    # Check whether any webcams were shared during the recording
+    # This can be used to e.g. skip webcam processing or change the layout
+    # of the final recording
+    def self.have_webcam_events(events_xml)
+      BigBlueButton.logger.debug("Checking if webcams were used...")
+      webcam_events = events_xml.xpath('/recording/event[@module="WEBCAM"]')
+      if webcam_events.length > 0
+        BigBlueButton.logger.debug("Webcam events seen in recording")
+        return true
+      else
+        BigBlueButton.logger.debug("No webcam events were seen in recording")
+        return false
+      end
+    end
+
+    # Check whether any of the presentation features were used in the recording
+    # This can be used to e.g. skip presentation processing or change the
+    # layout of the final recording.
+    def self.have_presentation_events(events_xml)
+      BigBlueButton.logger.debug("Checking if presentation area was used...")
+      pres_events = events_xml.xpath('/recording/event[@module="PRESENTATION" or @module="WHITEBOARD"]')
+      seen_share_presentation = false
+      pres_events.each do |event|
+        case event['eventname']
+        # The following events are considered to indicate that the presentation
+        # area was actively used during the session.
+        when 'AddShapeEvent', 'ModifyTextEvent', 'UndoShapeEvent',
+            'ClearPageEvent'
+        BigBlueButton.logger.debug("Seen a #{event['eventname']} event, presentation area used.")
+          return true
+        # We ignore the first SharePresentationEvent, since it's the default
+        # presentation
+        when 'SharePresentationEvent'
+          if seen_share_presentation
+            BigBlueButton.logger.debug("Have a non-default SharePresentation")
+            return true
+          else
+            BigBlueButton.logger.debug("Skipping default SharePresentation")
+            seen_share_presentation = true
+          end
+        # We ignore the 'GotoSlideEvent' for page 0 (first page)
+        when 'GotoSlideEvent'
+          slide = event.at_xpath('./slide').content.to_i
+          if slide != 0
+            BigBlueButton.logger.debug("Switched to slide #{slide}")
+            return true
+          end
+          BigBlueButton.logger.debug("Ignoring GotoSlide with default slide #")
+        end
+      end
+      BigBlueButton.logger.debug("No important presentation events found")
+      return false
+    end
+
     # Version of the bbb server where it was recorded
     def self.bbb_version(events_xml)
       events = Nokogiri::XML(File.open(events_xml))      

record-and-playback/core/lib/recordandplayback/generators/presentation.rb

@@ -42,15 +42,6 @@ module BigBlueButton
       Dir.glob("#{presentation_dir}/*.swf").size
     end
 
-    # Extract a page from the pdf file.
-    def self.extract_page_from_pdf(page_num, pdf_presentation, pdf_out)
-      BigBlueButton.logger.info("Task: Extracting a page from pdf file")
-      temp_out = "#{File.dirname(pdf_out)}/temp-#{File.basename(pdf_out)}"
-      command = "pdfseparate -f #{page_num} -l #{page_num} #{pdf_presentation} #{temp_out}"
-      BigBlueButton.execute(command)
-      FileUtils.mv(temp_out, pdf_out)
-    end
-
     # Extract a page from a pdf file as a png image
     def self.extract_png_page_from_pdf(page_num, pdf_presentation, png_out, resize = '800x600')
       BigBlueButton.logger.info("Task: Extracting a page from pdf file as png image")

record-and-playback/core/lib/recordandplayback/generators/video.rb

@@ -490,6 +490,10 @@ module BigBlueButton
       "#{temp_dir}/#{meeting_id}")
     BigBlueButton::EDL::Audio.dump(audio_edl)
 
+    BigBlueButton.logger.info("Applying recording start stop events:")
+    audio_edl = BigBlueButton::Events.edl_match_recording_marks_audio(audio_edl, "#{temp_dir}/#{meeting_id}")
+    BigBlueButton::EDL::Audio.dump(audio_edl)
+
     audio_file = BigBlueButton::EDL::Audio.render(
       audio_edl, "#{target_dir}/webcams")
 
@@ -498,8 +502,13 @@ module BigBlueButton
       "#{temp_dir}/#{meeting_id}")
     deskshare_edl = BigBlueButton::Events.create_deskshare_edl(
       "#{temp_dir}/#{meeting_id}")
-    temporary_video_edl = BigBlueButton::EDL::Video.merge(webcam_edl, deskshare_edl)
+    video_edl = BigBlueButton::EDL::Video.merge(webcam_edl, deskshare_edl)
-    video_edl = BigBlueButton::Events.edl_match_recording_marks_video(temporary_video_edl, "#{temp_dir}/#{meeting_id}")
+    BigBlueButton.logger.debug("Merged video EDL:")
+    BigBlueButton::EDL::Video.dump(video_edl)
+
+    BigBlueButton.logger.debug("Applying recording start stop events:")
+    video_edl = BigBlueButton::Events.edl_match_recording_marks_video(video_edl,
+                    "#{temp_dir}/#{meeting_id}")
     BigBlueButton::EDL::Video.dump(video_edl)
 
     layout = {
@@ -518,9 +527,10 @@ module BigBlueButton
       {
         :extension => 'webm',
         :parameters => [
-          [ '-c:v', 'libvpx', '-crf', '34', '-b:v', '60M',
+          [ '-c:v', 'libvpx',
-            '-threads', '2', '-deadline', 'good', '-cpu-used', '3',
+            '-crf', '34', '-b:v', '60M', '-threads', '2', '-deadline', 'good', '-cpu-used', '3',
-            '-c:a', 'libvorbis', '-b:a', '48K',
+            '-c:a', 'libvorbis',
+            '-q:a', '2',
             '-f', 'webm' ]
         ],
         :postprocess => [

record-and-playback/core/spec/recordandplayback/presentation_processor_spec.rb

@@ -37,29 +37,6 @@ module BigBlueButton
         BigBlueButton::Presentation.get_number_of_pages_for(presentations_dir).should equal(6)
       end
       
-      it "should extract each page from the presentation" do
-        dir = "resources/raw/1b199e88-7df7-4842-a5f1-0e84b781c5c8"
-        presentation = "#{dir}/presentations/aSimple-Layout/aSimple-Layout.pdf"
-        temp_dir = "/tmp/simple"
-        if FileTest.directory?(temp_dir)
-          FileUtils.remove_dir temp_dir
-        end
-        FileUtils.mkdir_p temp_dir
-
-        1.upto(6) do |x|
-          BigBlueButton::Presentation.extract_page_from_pdf(x, presentation, "#{temp_dir}/slide-#{x}.pdf")
-        end
-        Dir.glob("#{temp_dir}/*.pdf").size.should equal(6)
-        
-        1.upto(6) do |x|
-          BigBlueButton::Presentation.convert_pdf_to_png("#{temp_dir}/slide-#{x}.pdf", "#{temp_dir}/slide-#{x}.png")        
-        end
-                
-        Dir.glob("#{temp_dir}/*.png").size.should equal(6)
-        
-        FileUtils.remove_dir temp_dir
-      end
-      
     end
   end
-end
+end