From e4735a12b36254951b58c9a832c4ec19034483b2 Mon Sep 17 00:00:00 2001 From: Calvin Walton Date: Fri, 12 Aug 2016 14:17:51 -0400 Subject: [PATCH] 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. --- .../core/lib/recordandplayback/edl.rb | 5 +- .../core/lib/recordandplayback/edl/audio.rb | 12 +- .../core/lib/recordandplayback/edl/video.rb | 23 +- .../generators/audio_processor.rb | 9 +- .../recordandplayback/generators/events.rb | 248 +++++++++++------- .../generators/presentation.rb | 9 - .../lib/recordandplayback/generators/video.rb | 20 +- .../presentation_processor_spec.rb | 25 +- 8 files changed, 205 insertions(+), 146 deletions(-) diff --git a/record-and-playback/core/lib/recordandplayback/edl.rb b/record-and-playback/core/lib/recordandplayback/edl.rb index fd1ee8f046..5c4778306f 100644 --- a/record-and-playback/core/lib/recordandplayback/edl.rb +++ b/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'] - FFPROBE = ['ffprobe', '-v', 'warning', '-print_format', 'json', '-show_format', '-show_streams', '-count_frames'] + # max_error_rate is set to ignore errors in poorly encoded webcams/deskshare + 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]}" diff --git a/record-and-playback/core/lib/recordandplayback/edl/audio.rb b/record-and-playback/core/lib/recordandplayback/edl/audio.rb index 671e0a09a5..109775029a 100644 --- a/record-and-playback/core/lib/recordandplayback/edl/audio.rb +++ b/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_ARGS = ['-c:a', FFMPEG_WF_CODEC, '-f', 'wav'] - WF_EXT = 'wav' + FFMPEG_WF_CODEC = 'flac' + FFMPEG_WF_ARGS = ['-c:a', FFMPEG_WF_CODEC, '-f', 'flac'] + 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 diff --git a/record-and-playback/core/lib/recordandplayback/edl/video.rb b/record-and-playback/core/lib/recordandplayback/edl/video.rb index f6d20901af..5057873abc 100644 --- a/record-and-playback/core/lib/recordandplayback/edl/video.rb +++ b/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, '-'] diff --git a/record-and-playback/core/lib/recordandplayback/generators/audio_processor.rb b/record-and-playback/core/lib/recordandplayback/generators/audio_processor.rb index 06c29b0d28..c0e16b3053 100755 --- a/record-and-playback/core/lib/recordandplayback/generators/audio_processor.rb +++ b/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) diff --git a/record-and-playback/core/lib/recordandplayback/generators/events.rb b/record-and-playback/core/lib/recordandplayback/generators/events.rb index f5b22825f2..23b7c2fa11 100755 --- a/record-and-playback/core/lib/recordandplayback/generators/events.rb +++ b/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[:audio][:timestamp] += offset if edl_entry[:audio] + edl_entry_offset = Proc.new do |edl_entry, offset| + 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 - - empty_entry = { - :timestamp => nil, - :audio => nil - } - - return edl_match_recording_marks(edl, archive_dir, calculate_entry_files_timestamp, empty_entry) + edl_empty_entry = Proc.new do + { :audio => nil } + end + return BigBlueButton::Events.edl_match_recording_marks(edl, archive_dir, + edl_entry_offset, edl_empty_entry) end def self.edl_match_recording_marks_video(edl, archive_dir) - calculate_entry_files_timestamp = Proc.new do |edl_entry, offset| - if edl_entry[:areas][:webcam] - edl_entry[:areas][:webcam].each do |webcam_entry| - webcam_entry[:timestamp] += offset - end - end - if edl_entry[:areas][:deskshare] - edl_entry[:areas][:deskshare].each do |deskshare_entry| - deskshare_entry[:timestamp] += offset + edl_entry_offset = Proc.new do |edl_entry, offset| + new_entry = { :areas => {} } + edl_entry[:areas].each do |area, videos| + new_entry[:areas][area] = [] + videos.each do |video| + new_entry[:areas][area] << { + :filename => video[:filename], + :timestamp => video[:timestamp] + offset + } end end + new_entry end - - empty_entry = { - :timestamp => nil, - :areas => { :webcam => [], :deskshare => [] } - } - - return edl_match_recording_marks(edl, archive_dir, calculate_entry_files_timestamp, empty_entry) + edl_empty_entry = Proc.new do + { :areas => {} } + end + return BigBlueButton::Events.edl_match_recording_marks(edl, archive_dir, + edl_entry_offset, edl_empty_entry) end - def self.edl_match_recording_marks_deskshare(edl, archive_dir) - calculate_entry_files_timestamp = Proc.new do |edl_entry, offset| - edl_entry[:areas][:deskshare].each do |webcam_entry| - webcam_entry[:timestamp] += offset - end - end - - 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 + def self.get_start_stop_events_for_edl(archive_dir) + initial_timestamp = BigBlueButton::Events.first_event_timestamp( + "#{archive_dir}/events.xml") + start_stop_events = BigBlueButton::Events.match_start_and_stop_rec_events( + BigBlueButton::Events.get_start_and_stop_rec_events( + "#{archive_dir}/events.xml")) 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 - edl.each_with_index do |edl_entry, i| - if i == edl.length-1 - edl_entry[:duration] = 0 - else - edl_entry[:duration] = edl[i+1][:timestamp] - edl_entry[:timestamp] + def self.edl_match_recording_marks(edl, archive_dir, edl_entry_offset, edl_empty_entry) + start_stop_events = BigBlueButton::Events.get_start_stop_events_for_edl(archive_dir) + + last_stop_timestamp = 0 + offset = 0 + + 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 = [] - start_stop_events.each do |record_event| - edl.each do |edl_entry| - edl_copy = Marshal.load(Marshal.dump(edl_entry)) + # Add the first event, trimming the start as needed. + initial_trim = start_stop_event[:start_timestamp] - edl[input_i][:timestamp] + BigBlueButton.logger.debug("Have to trim #{initial_trim}") + 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] - edl_stop = edl_entry[:timestamp] + edl_entry[:duration] - rec_start = record_event[:start_timestamp] - rec_stop = record_event[:stop_timestamp] + # Add the intervening events up to the stop + loop do + input_i += 1 + break if edl[input_i][:timestamp] >= start_stop_event[:stop_timestamp] - # edl doesn't match with the recording marks - if (edl_start < rec_start and edl_stop < rec_start) or (edl_start > rec_stop and edl_stop > rec_stop) - next - end + new_edl[output_i] = edl_entry_offset.call(edl[input_i], 0) + new_edl[output_i][:timestamp] = edl[input_i][:timestamp] - offset - # adjust the beginning timestamp - 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 + output_i += 1 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 - 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 + return new_edl 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)) diff --git a/record-and-playback/core/lib/recordandplayback/generators/presentation.rb b/record-and-playback/core/lib/recordandplayback/generators/presentation.rb index a89e01ae25..775f12aad0 100755 --- a/record-and-playback/core/lib/recordandplayback/generators/presentation.rb +++ b/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") diff --git a/record-and-playback/core/lib/recordandplayback/generators/video.rb b/record-and-playback/core/lib/recordandplayback/generators/video.rb index c9d5768b3a..dc8fd07eec 100755 --- a/record-and-playback/core/lib/recordandplayback/generators/video.rb +++ b/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::Events.edl_match_recording_marks_video(temporary_video_edl, "#{temp_dir}/#{meeting_id}") + video_edl = BigBlueButton::EDL::Video.merge(webcam_edl, deskshare_edl) + 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', - '-threads', '2', '-deadline', 'good', '-cpu-used', '3', - '-c:a', 'libvorbis', '-b:a', '48K', + [ '-c:v', 'libvpx', + '-crf', '34', '-b:v', '60M', '-threads', '2', '-deadline', 'good', '-cpu-used', '3', + '-c:a', 'libvorbis', + '-q:a', '2', '-f', 'webm' ] ], :postprocess => [ diff --git a/record-and-playback/core/spec/recordandplayback/presentation_processor_spec.rb b/record-and-playback/core/spec/recordandplayback/presentation_processor_spec.rb index 9f55418632..b69a6d79e7 100755 --- a/record-and-playback/core/spec/recordandplayback/presentation_processor_spec.rb +++ b/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 \ No newline at end of file +end