How do I troubleshoot a failed video upload (Carrierwave) if no errors being sent to log?

Question

I am doing a video upload with Carrierwave, and it keeps failing. But the log doesn't show me what's wrong.

This is my video_uploader.rb:

class VideoUploader < CarrierWave::Uploader::Base    
  storage :fog

  def content_type_whitelist
    /video\//
  end

  def extension_whitelist
    %w(mp4 mov wmv mpeg4 avi 3gpp webm)
  end    
end

This is what my log looks like of the successful update action (which includes the new file to be uploaded):

Started PATCH "/profiles/kristin-walter-jamaica-college" for ::1 at 2016-10-19 05:22:56 -0500
Processing by ProfilesController#update as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"YBrqV==", "profile"=>{"remove_avatar"=>"0", "avatar_cache"=>"", "first_name"=>"Kristin", "last_name"=>"Walter", "dob(3i)"=>"1", "dob(2i)"=>"5", "dob(1i)"=>"1998", "weight"=>"249", "height"=>"85", "bib_color"=>"19", "player_type"=>"player", "video_url"=>"https://www.youtube.com/embed/a4k", "position_ids"=>[""], "school_id"=>"2", "grade"=>"", "grades_attributes"=>{"0"=>{"subject"=>"", "result"=>"", "grade_type"=>"csec", "_destroy"=>"false"}}, "transcript_cache"=>"", "achievements_attributes"=>{"0"=>{"body"=>"", "achievement_type"=>"academic", "_destroy"=>"false"}}, "videos_attributes"=>{"0"=>{"url"=>"", "remove_video"=>"0", "video"=>#<ActionDispatch::Http::UploadedFile:0x007fbccc812f28 @tempfile=#<Tempfile:/var/folders/0f/hgplttnd7dg6q9m62qtbnpn00000gn/T/RackMultipart20161019-12863-159wlxq.MOV>, @original_filename="P8250323.MOV", @content_type="video/quicktime", @headers="Content-Disposition: form-data; name=\"profile[videos_attributes][0][video]\"; filename=\"P8250323.MOV\"\r\nContent-Type: video/quicktime\r\n">, "video_cache"=>"", "vimeo_url"=>"", "vimeo_embed_code"=>"", "official"=>"", "_destroy"=>"false", "id"=>"4"}, "1"=>{"url"=>"", "remove_video"=>"0", "video_cache"=>"", "vimeo_url"=>"", "vimeo_embed_code"=>"", "official"=>"", "_destroy"=>"false"}}, "articles_attributes"=>{"0"=>{"source"=>"Gleaner", "title"=>"JC Off The Mark With Easy Win", "url"=>"http://jamaica-gleaner.com/article/sports/20160911/jc-mark-easy-win", "_destroy"=>"false", "id"=>"1"}, "1"=>{"source"=>"", "title"=>"", "url"=>"", "_destroy"=>"false"}}}, "commit"=>"Update Profile", "id"=>"kristin-walter-jamaica-college"}
  Profile Load (1.2ms)  SELECT  "profiles".* FROM "profiles" WHERE "profiles"."slug" = $1 ORDER BY "profiles"."id" ASC LIMIT $2  [["slug", "kristin-walter-jamaica-college"], ["LIMIT", 1]]
  Grade Load (1.0ms)  SELECT "grades".* FROM "grades" WHERE "grades"."profile_id" = 9
  HABTM_Positions Load (1.0ms)  SELECT "positions_profiles".* FROM "positions_profiles" WHERE "positions_profiles"."profile_id" = 9
  Achievement Load (1.0ms)  SELECT "achievements".* FROM "achievements" WHERE "achievements"."profile_id" = 9
   (0.9ms)  SELECT COUNT(*) FROM "videos" WHERE "videos"."profile_id" = $1  [["profile_id", 9]]
   (0.6ms)  BEGIN
  Position Load (1.1ms)  SELECT "positions".* FROM "positions" WHERE 1=0
  Article Load (1.1ms)  SELECT "articles".* FROM "articles" WHERE "articles"."profile_id" = $1 AND "articles"."id" = 1  [["profile_id", 9]]
  Video Load (1.9ms)  SELECT "videos".* FROM "videos" WHERE "videos"."profile_id" = $1 AND "videos"."id" = 4  [["profile_id", 9]]
  SQL (3.3ms)  UPDATE "profiles" SET "updated_at" = $1, "avatar" = $2 WHERE "profiles"."id" = $3  [["updated_at", 2016-10-19 10:22:56 UTC], ["avatar", "Recrutz-6.jpg"], ["id", 9]]
   (78.2ms)  COMMIT
Redirected to http://localhost:3000/profiles/kristin-walter-jamaica-college
Completed 302 Found in 126ms (ActiveRecord: 91.2ms)

This my Video.rb model:

class Video < ApplicationRecord
  mount_uploader :video, VideoUploader
  belongs_to :profile
end

This is my profile_controller#update.rb, which is where the associated video object is being uploaded from:

  def update    
    respond_to do |format|
      if @profile.update(profile_params)
        format.html { redirect_to @profile, notice: 'Profile was successfully updated.' }
        format.json { render :show, status: :ok, location: @profile }
      else
        format.html { redirect_to edit_profile_path(@profile), message: @profile.errors.messages }
        format.json { render json: @profile.errors, status: :unprocessable_entity }
      end
    end
  end

This is the relevant portion of the _form.html.erb:

  <h3 class="text-center">Videos</h3>

  <div id="videos" class="text-center">
    <%= f.simple_fields_for :videos do |video| %>
      <%= render 'video_fields', f: video %>
    <% end %>
    <div class="links">
      <%= link_to_add_association 'Add Video', f, :videos, class: "btn btn-success add-grade-button" %>
    </div>
  </div>

This is the _video_fields.html.erb partial referenced in the _form partial (truncated for brevity):

          <%= f.input_field :url, class: 'form-control' %>
            <% if !@profile.videos.empty? %>
              <% @profile.videos.each do |video| %>
                <%= video.video_identifier %>
                <label>
                  <%= f.check_box :remove_video %>
                  Remove video
                </label>
              <% end %>
            <% end %>
            <%= f.file_field :video, class: 'form-control' %>
            <%= f.input_field :video_cache, as: :hidden, class: 'form-control '%>
           <%= f.input_field :vimeo_url, class: 'form-control' %>
           <%= f.input_field :vimeo_embed_code, class: 'form-control' %>
    <%= f.input_field :official, as: :radio_buttons, class: 'form-control' %>        
      <% end %>

I have two other uploaders for images & documents, and they work fine. For some reason, this one doesn't work.

It creates the folder on S3, but it doesn't actually upload the file.

How do I troubleshoot this?

Edit 1

In my profile.rb model, I have the following:

  has_many :videos, dependent: :destroy
  accepts_nested_attributes_for :videos, reject_if: :reject_videos, allow_destroy: true

Edit 2

This is the log output when I upload a file that should NOT work, i.e. an image in the video upload. Nothing obvious happens. It just fails silently.

Started PATCH "/profiles/kristin-walter-jamaica-college" for ::1 at 2016-10-20 02:21:37 -0500
Processing by ProfilesController#update as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"390ImtDcSl4RoEZA==", "profile"=>{"remove_avatar"=>"0", "avatar_cache"=>"", "first_name"=>"Kristin", "last_name"=>"Walter", "dob(3i)"=>"1", "dob(2i)"=>"5", "dob(1i)"=>"1998", "weight"=>"249", "height"=>"85", "bib_color"=>"19", "player_type"=>"player", "video_url"=>"https://www.youtube.com/embed/Rpa4k", "position_ids"=>[""], "school_id"=>"2", "grade"=>"", "grades_attributes"=>{"0"=>{"subject"=>"", "result"=>"", "grade_type"=>"csec", "_destroy"=>"false"}}, "transcript_cache"=>"", "achievements_attributes"=>{"0"=>{"body"=>"", "achievement_type"=>"academic", "_destroy"=>"false"}}, "videos_attributes"=>{"0"=>{"url"=>"", "remove_video"=>"0", "video"=>#<ActionDispatch::Http::UploadedFile:0x007fdff5b64c48 @tempfile=#<Tempfile:/var/folders/0f/hgplttnd7dg6q9m62qtbnpn00000gn/T/RackMultipart20161020-27906-95t0fg.jpg>, @original_filename="Photo Oct 13, 3 36 47 PM.jpg", @content_type="image/jpeg", @headers="Content-Disposition: form-data; name=\"profile[videos_attributes][0][video]\"; filename=\"Photo Oct 13, 3 36 47 PM.jpg\"\r\nContent-Type: image/jpeg\r\n">, "video_cache"=>"", "vimeo_url"=>"", "vimeo_embed_code"=>"", "official"=>"", "_destroy"=>"false", "id"=>"4"}, "1"=>{"url"=>"", "remove_video"=>"0", "video_cache"=>"", "vimeo_url"=>"", "vimeo_embed_code"=>"", "official"=>"", "_destroy"=>"false"}}, "articles_attributes"=>{"0"=>{"source"=>"Gleaner", "title"=>"JC Off The Mark With Easy Win", "url"=>"http://jamaica-gleaner.com/article/sports/20160911/jc-mark-easy-win", "_destroy"=>"false", "id"=>"1"}, "1"=>{"source"=>"", "title"=>"", "url"=>"", "_destroy"=>"false"}}}, "commit"=>"Update Profile", "id"=>"kristin-walter-jamaica-college"}
  Profile Load (1.1ms)  SELECT  "profiles".* FROM "profiles" WHERE "profiles"."slug" = $1 ORDER BY "profiles"."id" ASC LIMIT $2  [["slug", "kristin-walter-jamaica-college"], ["LIMIT", 1]]
  Grade Load (0.8ms)  SELECT "grades".* FROM "grades" WHERE "grades"."profile_id" = 9
  HABTM_Positions Load (1.1ms)  SELECT "positions_profiles".* FROM "positions_profiles" WHERE "positions_profiles"."profile_id" = 9
  Achievement Load (1.0ms)  SELECT "achievements".* FROM "achievements" WHERE "achievements"."profile_id" = 9
   (0.8ms)  SELECT COUNT(*) FROM "videos" WHERE "videos"."profile_id" = $1  [["profile_id", 9]]
   (1.0ms)  BEGIN
  Position Load (1.2ms)  SELECT "positions".* FROM "positions" WHERE 1=0
  Article Load (1.0ms)  SELECT "articles".* FROM "articles" WHERE "articles"."profile_id" = $1 AND "articles"."id" = 1  [["profile_id", 9]]
  Video Load (0.9ms)  SELECT "videos".* FROM "videos" WHERE "videos"."profile_id" = $1 AND "videos"."id" = 4  [["profile_id", 9]]
  SQL (1.9ms)  UPDATE "profiles" SET "updated_at" = $1, "avatar" = $2 WHERE "profiles"."id" = $3  [["updated_at", 2016-10-20 07:21:37 UTC], ["avatar", "Recrutz-6.jpg"], ["id", 9]]
   (111.8ms)  COMMIT
Redirected to http://localhost:3000/profiles/kristin-walter-jamaica-college
Completed 302 Found in 151ms (ActiveRecord: 122.6ms)

Edit 3

As a point of comparison, here is the log from the update operation of a successful avatar upload -- note this is governed by a different model, and different uploader, etc. But just to show what the log looks like when it actually uploads successfully.

Started PATCH "/profiles/kristin-walter-jamaica-college" for ::1 at 2016-10-20 05:52:41 -0500
Processing by ProfilesController#update as HTML
  Parameters: {"utf8"=>"✓", "authenticity_token"=>"RqAORU3Iw==", "profile"=>{"avatar"=>#<ActionDispatch::Http::UploadedFile:0x007fdff618de58 @tempfile=#<Tempfile:/var/folders/0f/hgplttnd7dg6q9m62qtbnpn00000gn/T/RackMultipart20161020-27906-1cg2dxq.jpg>, @original_filename="DSC_0010.jpg", @content_type="image/jpeg", @headers="Content-Disposition: form-data; name=\"profile[avatar]\"; filename=\"DSC_0010.jpg\"\r\nContent-Type: image/jpeg\r\n">, "avatar_cache"=>"", "first_name"=>"Kristin", "last_name"=>"Walter", "dob(3i)"=>"1", "dob(2i)"=>"5", "dob(1i)"=>"1998", "weight"=>"249", "height"=>"85", "bib_color"=>"19", "player_type"=>"player", "video_url"=>"https://www.youtube.com/Rpa4k", "position_ids"=>[""], "school_id"=>"2", "grade"=>"", "grades_attributes"=>{"0"=>{"subject"=>"", "result"=>"", "grade_type"=>"csec", "_destroy"=>"false"}}, "transcript_cache"=>"", "achievements_attributes"=>{"0"=>{"body"=>"", "achievement_type"=>"academic", "_destroy"=>"false"}}, "videos_attributes"=>{"0"=>{"url"=>"", "remove_video"=>"0", "video_cache"=>"", "vimeo_url"=>"", "vimeo_embed_code"=>"", "official"=>"", "_destroy"=>"false", "id"=>"4"}, "1"=>{"url"=>"", "remove_video"=>"0", "video_cache"=>"", "vimeo_url"=>"", "vimeo_embed_code"=>"", "official"=>"", "_destroy"=>"false"}}, "articles_attributes"=>{"0"=>{"source"=>"Gleaner", "title"=>"JC Off The Mark With Easy Win", "url"=>"http://jamaica-gleaner.com/article/sports/20160911/jc-mark-easy-win", "_destroy"=>"false", "id"=>"1"}, "1"=>{"source"=>"", "title"=>"", "url"=>"", "_destroy"=>"false"}}}, "commit"=>"Update Profile", "id"=>"kristin-walter-jamaica-college"}
  Profile Load (1.3ms)  SELECT  "profiles".* FROM "profiles" WHERE "profiles"."slug" = $1 ORDER BY "profiles"."id" ASC LIMIT $2  [["slug", "kristin-walter-jamaica-college"], ["LIMIT", 1]]
  Grade Load (1.0ms)  SELECT "grades".* FROM "grades" WHERE "grades"."profile_id" = 9
  HABTM_Positions Load (1.3ms)  SELECT "positions_profiles".* FROM "positions_profiles" WHERE "positions_profiles"."profile_id" = 9
  Achievement Load (1.0ms)  SELECT "achievements".* FROM "achievements" WHERE "achievements"."profile_id" = 9
   (0.9ms)  SELECT COUNT(*) FROM "videos" WHERE "videos"."profile_id" = $1  [["profile_id", 9]]
   (0.6ms)  BEGIN
  Position Load (0.8ms)  SELECT "positions".* FROM "positions" WHERE 1=0
  Article Load (1.4ms)  SELECT "articles".* FROM "articles" WHERE "articles"."profile_id" = $1 AND "articles"."id" = 1  [["profile_id", 9]]
  Video Load (1.3ms)  SELECT "videos".* FROM "videos" WHERE "videos"."profile_id" = $1 AND "videos"."id" = 4  [["profile_id", 9]]
  SQL (2.3ms)  UPDATE "profiles" SET "avatar" = $1, "updated_at" = $2 WHERE "profiles"."id" = $3  [["avatar", "DSC_0010.jpg"], ["updated_at", 2016-10-20 10:52:41 UTC], ["id", 9]]
   (1.3ms)  COMMIT
Redirected to http://localhost:3000/profiles/kristin-walter-jamaica-college
Completed 302 Found in 1053ms (ActiveRecord: 13.4ms)