diff --git a/db/manifest b/db/manifest index 5a4689017..7f3451da3 100755 --- a/db/manifest +++ b/db/manifest @@ -276,4 +276,5 @@ jam_track_duration.sql sales.sql show_whats_next_count.sql recurly_adjustments.sql -signup_hints.sql \ No newline at end of file +signup_hints.sql +packaging_notices.sql \ No newline at end of file diff --git a/db/up/packaging_notices.sql b/db/up/packaging_notices.sql new file mode 100644 index 000000000..d3a5de551 --- /dev/null +++ b/db/up/packaging_notices.sql @@ -0,0 +1,3 @@ +ALTER TABLE jam_track_rights ADD COLUMN packaging_steps INTEGER; +ALTER TABLE jam_track_rights ADD COLUMN current_packaging_step INTEGER; +ALTER TABLE jam_track_rights ADD COLUMN last_step_at TIMESTAMP; diff --git a/ruby/lib/jam_ruby/jam_tracks_manager.rb b/ruby/lib/jam_ruby/jam_tracks_manager.rb index 9322c3dbd..36a19c960 100644 --- a/ruby/lib/jam_ruby/jam_tracks_manager.rb +++ b/ruby/lib/jam_ruby/jam_tracks_manager.rb @@ -22,9 +22,21 @@ module JamRuby save_jam_track_right_jkz(jam_track_right, sample_rate) end + # increment the step, which causes a notification to be sent to the client so it can keep the UI fresh as the packaging step goes on + def bump_step(jam_track_right, step) + last_step_at = Time.now + jam_track_right.current_packaging_step = step + jam_track_right.last_step_at = Time.now + JamTrackRight.where(:id => jam_track_right.id).update_all(last_step_at: last_step_at, current_packaging_step: step) + SubscriptionMessage.jam_track_signing_job_change(jam_track_right) + step = step + 1 + step + end + def save_jam_track_right_jkz(jam_track_right, sample_rate=48) jam_track = jam_track_right.jam_track py_root = APP_CONFIG.jamtracks_dir + step = 0 Dir.mktmpdir do |tmp_dir| jam_file_opts="" jam_track.jam_track_tracks.each do |jam_track_track| @@ -36,6 +48,9 @@ module JamRuby track_filename = File.join(tmp_dir, nm) track_url = jam_track_track.sign_url(120, sample_rate) @@log.info("downloading #{track_url} to #{track_filename}") + + step = bump_step(jam_track_right, step) + copy_url_to_file(track_url, track_filename) jam_file_opts << " -i #{Shellwords.escape("#{track_filename}+#{jam_track_track.part}")}" end @@ -48,6 +63,8 @@ module JamRuby version = jam_track.version @@log.info "Executing python source in #{py_file}, outputting to #{tmp_dir} (#{output_jkz})" + step = bump_step(jam_track_right, step) + # From http://stackoverflow.com/questions/690151/getting-output-of-system-calls-in-ruby/5970819#5970819: cli = "python #{py_file} -D -k #{sku} -p #{Shellwords.escape(tmp_dir)}/pkey.pem -s #{Shellwords.escape(tmp_dir)}/skey.pem #{jam_file_opts} -o #{Shellwords.escape(output_jkz)} -t #{Shellwords.escape(title)} -V #{Shellwords.escape(version)}" Open3.popen3(cli) do |stdin, stdout, stderr, wait_thr| diff --git a/ruby/lib/jam_ruby/lib/subscription_message.rb b/ruby/lib/jam_ruby/lib/subscription_message.rb index ec161ec8f..6be9f7d16 100644 --- a/ruby/lib/jam_ruby/lib/subscription_message.rb +++ b/ruby/lib/jam_ruby/lib/subscription_message.rb @@ -22,7 +22,7 @@ module JamRuby end def self.jam_track_signing_job_change(jam_track_right) - Notification.send_subscription_message('jam_track_right', jam_track_right.id.to_s, {signing_state: jam_track_right.signing_state}.to_json ) + Notification.send_subscription_message('jam_track_right', jam_track_right.id.to_s, {signing_state: jam_track_right.signing_state, current_packaging_step: jam_track_right.current_packaging_step, packaging_steps: jam_track_right.packaging_steps}.to_json ) end end end diff --git a/ruby/lib/jam_ruby/models/jam_track.rb b/ruby/lib/jam_ruby/models/jam_track.rb index f05643c86..a15093d8b 100644 --- a/ruby/lib/jam_ruby/models/jam_track.rb +++ b/ruby/lib/jam_ruby/models/jam_track.rb @@ -195,6 +195,10 @@ module JamRuby JamTrackTrack.where(jam_track_id: self.id).where(track_type: 'Master').first end + def stem_tracks + JamTrackTrack.where(jam_track_id: self.id).where(track_type: 'Track') + end + def can_download?(user) owners.include?(user) end diff --git a/ruby/lib/jam_ruby/models/jam_track_right.rb b/ruby/lib/jam_ruby/models/jam_track_right.rb index f5abb1353..fe4631d84 100644 --- a/ruby/lib/jam_ruby/models/jam_track_right.rb +++ b/ruby/lib/jam_ruby/models/jam_track_right.rb @@ -29,7 +29,7 @@ module JamRuby # try to catch major transitions: # if just queue time changes, start time changes, or signed time changes, send out a notice - if signing_queued_at_was != signing_queued_at || signing_started_at_was != signing_started_at || last_signed_at_was != last_signed_at + if signing_queued_at_was != signing_queued_at || signing_started_at_was != signing_started_at || last_signed_at_was != last_signed_at || current_packaging_step != current_packaging_step_was || packaging_steps != packaging_steps_was SubscriptionMessage.jam_track_signing_job_change(self) end end @@ -148,7 +148,11 @@ module JamRuby if signed state = 'SIGNED' elsif signing_started_at - if Time.now - signing_started_at > APP_CONFIG.signing_job_run_max_time + # the maximum amount of time the packaging job can take is 10 seconds * num steps. For a 10 track song, this will be 110 seconds. It's a bit long. + signing_job_run_max_time = packaging_steps * 10 + if Time.now - signing_started_at > signing_job_run_max_time + state = 'SIGNING_TIMEOUT' + elsif Time.now - last_step_at > APP_CONFIG.signing_step_max_time state = 'SIGNING_TIMEOUT' else state = 'SIGNING' diff --git a/ruby/lib/jam_ruby/resque/jam_tracks_builder.rb b/ruby/lib/jam_ruby/resque/jam_tracks_builder.rb index 395d12084..329a52b4d 100644 --- a/ruby/lib/jam_ruby/resque/jam_tracks_builder.rb +++ b/ruby/lib/jam_ruby/resque/jam_tracks_builder.rb @@ -34,8 +34,20 @@ module JamRuby return end + # compute the step count + total_steps = @jam_track_right.jam_track.stem_tracks.count + 1 # the '1' represents the jkz.py invocation + # track that it's started ( and avoid db validations ) - JamTrackRight.where(:id => @jam_track_right.id).update_all(:signing_started_at => Time.now, :should_retry => false) + signing_started_at = Time.now + last_step_at = Time.now + JamTrackRight.where(:id => @jam_track_right.id).update_all(:signing_started_at => signing_started_at, :should_retry => false, packaging_steps: total_steps, current_packaging_step: 0, last_step_at: last_step_at) + # because we are skiping after_save, we have to keep the model current for the notification. A bit ugly... + @jam_track_right.current_packaging_step = 0 + @jam_track_right.packaging_steps = total_steps + @jam_track_right.signing_started_at = signing_started_at + @jam_track_right.should_retry = false + @jam_track_right.last_step_at = Time.now + SubscriptionMessage.jam_track_signing_job_change(@jam_track_right) JamRuby::JamTracksManager.save_jam_track_right_jkz(@jam_track_right, self.bitrate) # If bitrate is 48 (the default), use that URL. Otherwise, use 44kHz: diff --git a/ruby/spec/jam_ruby/models/jam_track_right_spec.rb b/ruby/spec/jam_ruby/models/jam_track_right_spec.rb index 530535f8c..0977703ff 100644 --- a/ruby/spec/jam_ruby/models/jam_track_right_spec.rb +++ b/ruby/spec/jam_ruby/models/jam_track_right_spec.rb @@ -134,12 +134,12 @@ describe JamTrackRight do end it "signing" do - right = FactoryGirl.create(:jam_track_right, signing_started_at: Time.now) + right = FactoryGirl.create(:jam_track_right, signing_started_at: Time.now, packaging_steps: 3, current_packaging_step:0, last_step_at:Time.now) right.signing_state.should eq('SIGNING') end it "signing timeout" do - right = FactoryGirl.create(:jam_track_right, signing_started_at: Time.now - (APP_CONFIG.signing_job_run_max_time + 1)) + right = FactoryGirl.create(:jam_track_right, signing_started_at: Time.now - 100, packaging_steps: 3, current_packaging_step:0, last_step_at:Time.now) right.signing_state.should eq('SIGNING_TIMEOUT') end diff --git a/ruby/spec/support/utilities.rb b/ruby/spec/support/utilities.rb index b22dd4467..e30f4b57d 100644 --- a/ruby/spec/support/utilities.rb +++ b/ruby/spec/support/utilities.rb @@ -166,8 +166,8 @@ def app_config false end - def signing_job_run_max_time - 60 # 1 minute + def signing_step_max_time + 40 # 40 seconds end def signing_job_queue_max_time diff --git a/web/app/assets/javascripts/checkout_order.js b/web/app/assets/javascripts/checkout_order.js index fbe41c665..5f2c20f36 100644 --- a/web/app/assets/javascripts/checkout_order.js +++ b/web/app/assets/javascripts/checkout_order.js @@ -56,6 +56,7 @@ } function beforeShowOrder() { + $purchasedJamTracks.empty() $orderPrompt.addClass('hidden') $emptyCartPrompt.addClass('hidden') $noAccountInfoPrompt.addClass('hidden') diff --git a/web/app/assets/javascripts/download_jamtrack.js.coffee b/web/app/assets/javascripts/download_jamtrack.js.coffee index 8442fec02..f1e3812a8 100644 --- a/web/app/assets/javascripts/download_jamtrack.js.coffee +++ b/web/app/assets/javascripts/download_jamtrack.js.coffee @@ -48,6 +48,8 @@ context.JK.DownloadJamTrack = class DownloadJamTrack @tracked = false @ajaxEnqueueAborted = false @ajaxGetJamTrackRightAborted = false + @currentPackagingStep = null + @totalSteps = null throw "no JamTrack specified" unless @jamTrack? throw "invalid size" if @size != 'large' && @size != 'small' @@ -374,8 +376,22 @@ context.JK.DownloadJamTrack = class DownloadJamTrack .done(this.processJamTrackRight) .fail(this.processJamTrackRightFail) + # update progress indicator for packaging step + updateSteps: () => + if @currentPackagingStep? and @totalSteps? + progress = "#{Math.round(@currentPackagingStep/@totalSteps * 100)}%" + else + progress = '...' + + @root.find('.progress').text(progress) + + processSigningState: (jamTrackRight) => + signingState = jamTrackRight.signing_state + @totalSteps = jamTrackRight.packaging_steps + @currentPackagingStep = jamTrackRight.current_packaging_step + + @updateSteps() - processSigningState: (signingState) => @logger.debug("DownloadJamTrack: processSigningState: " + signingState) switch signingState @@ -435,8 +451,9 @@ context.JK.DownloadJamTrack = class DownloadJamTrack processJamTrackRight: (myJamTrack) => + @logger.debug("processJamTrackRight", myJamTrack) unless @ajaxGetJamTrackRightAborted - this.processSigningState(myJamTrack.signing_state) + this.processSigningState(myJamTrack) else @logger.debug("DownloadJamTrack: ignoring processJamTrackRight response") @@ -459,9 +476,9 @@ context.JK.DownloadJamTrack = class DownloadJamTrack @logger.debug("DownloadJamTrack: ignoring processEnqueueJamTrackFail response") onJamTrackRightEvent: (e, data) => - @logger.debug("DownloadJamTrack: subscription notification received: type:" + data.type) + @logger.debug("DownloadJamTrack: subscription notification received: type:" + data.type, data) this.expectTransition() - this.processSigningState(data.body.signing_state) + this.processSigningState(data.body) downloadProgressCallback: (bytesReceived, bytesTotal, downloadSpeedMegSec, timeRemaining) => bytesReceived = Number(bytesReceived) diff --git a/web/app/views/api_jam_tracks/show_jam_track_right.rabl b/web/app/views/api_jam_tracks/show_jam_track_right.rabl index e72c3f5b4..365730236 100644 --- a/web/app/views/api_jam_tracks/show_jam_track_right.rabl +++ b/web/app/views/api_jam_tracks/show_jam_track_right.rabl @@ -1,3 +1,3 @@ object @jam_track_right -attributes :id, :signing_state, :error_count, :error_reason, :error_detail \ No newline at end of file +attributes :id, :error_count, :error_reason, :error_detail, :signing_state, :packaging_steps, :current_packaging_step \ No newline at end of file diff --git a/web/app/views/clients/_download_jamtrack_templates.html.slim b/web/app/views/clients/_download_jamtrack_templates.html.slim index fef7f2cd8..a98949fca 100644 --- a/web/app/views/clients/_download_jamtrack_templates.html.slim +++ b/web/app/views/clients/_download_jamtrack_templates.html.slim @@ -24,11 +24,15 @@ script type="text/template" id="template-download-jamtrack-state-packaging" .state-packaging .large.hidden .msg - | Your JamTrack is currently being created on the JamKazam server. + | Your JamTrack is currently being created on the JamKazam server. ( + span.progress + | ) .spinner-large .small.hidden .msg - | {{data.name}} (packaging) + | {{data.name}} (packaging - + span.progress + | ) .spinner-small script type="text/template" id="template-download-jamtrack-state-downloading" diff --git a/web/config/application.rb b/web/config/application.rb index 173220b55..0f2388802 100644 --- a/web/config/application.rb +++ b/web/config/application.rb @@ -215,10 +215,10 @@ if defined?(Bundler) config.jamtracks_dir = ENV['JAMTRACKS_DIR'] || File.expand_path(File.join(File.dirname(__FILE__), "..", "..", "..", "jamtracks")) config.jmep_dir = ENV['JMEP_DIR'] || File.expand_path(File.join(File.dirname(__FILE__), "..", "..", "..", "jmep")) - # amount of time before we think packaging job is broken - config.signing_job_run_max_time = 60 # 1 minute # amount of time before we think the queue is stuck config.signing_job_queue_max_time = 20 # 20 seconds + # amount of time to allow before giving up on a single step in packaging job + config.signing_step_max_time = 40; # 40 seconds config.email_alerts_alias = 'alerts@jamkazam.com' # should be used for 'oh no' server down/service down sorts of emails config.email_generic_from = 'nobody@jamkazam.com' diff --git a/web/spec/support/app_config.rb b/web/spec/support/app_config.rb index 645562f90..397954166 100644 --- a/web/spec/support/app_config.rb +++ b/web/spec/support/app_config.rb @@ -71,8 +71,8 @@ def web_config 100 end - def signing_job_run_max_time - 60 # 1 minute + def signing_step_max_time + 40 # 40 seconds end def signing_job_queue_max_time