Lmde7 branch

[a-j-bauer]

Current situation

(This time I double checked)

I added some debug output to GIO's gfile.c splice_stream_with_progress function to show the current situation.

When a file is copied to a slow block device like a USB thumb drive, the GIO's g_file_copy function
is called with a progress callback function pointer. This has to be called by the GIO's copy / move function to give visual
feedback to a human user. The user expects to see a meaningful dialog that shows how much of the file
is written to the device, a percentage and or remaining time estimate. All of this cannot be done if
the calls are not evenly distributed over the duration time range.

GIO does not have a copy function on it's iface for this in g_file_copy:

iface = G_FILE_GET_IFACE (destination);
  if (iface->copy)
    {   
    
...
...
return file_copy_fallback(..

so it uses the function file_copy_fallback which in the end uses splice.

The following is the function that GIO uses to write the data if the splice (splice data to/from a pipe)
function is available on the system. From the Linux manual page for splice:

splice() moves data between two file descriptors without copying
       between kernel address space and user address space.  It transfers
       up to size bytes of data from the file descriptor fd_in to the
       file descriptor fd_out, where one of the file descriptors must
       refer to a pipe.

GIO - gfile.c - with debug output:

#ifdef HAVE_SPLICE

static gboolean
splice_stream_with_progress (GInputStream           *in,
                             GFileInfo              *in_info,
                             GOutputStream          *out,
                             GCancellable           *cancellable,
                             GFileProgressCallback   progress_callback,
                             gpointer                progress_callback_data,
                             GError                **error)
{
  int buffer[2] = { -1, -1 };
  int buffer_size;
  gboolean res;
  goffset total_size;
  loff_t offset_in;
  loff_t offset_out;
  int fd_in, fd_out;

  fd_in = g_file_descriptor_based_get_fd (G_FILE_DESCRIPTOR_BASED (in));
  fd_out = g_file_descriptor_based_get_fd (G_FILE_DESCRIPTOR_BASED (out));

  if (!g_unix_open_pipe (buffer, O_CLOEXEC, error))
    return FALSE;

  /* Try a 1MiB buffer for improved throughput. If that fails, use the default
   * pipe size. See: https://bugzilla.gnome.org/791457 */
  buffer_size = fcntl (buffer[1], F_SETPIPE_SZ, 1024 * 1024);
  if (buffer_size <= 0)
    {
      buffer_size = fcntl (buffer[1], F_GETPIPE_SZ);
      if (buffer_size <= 0)
        {
          /* If #F_GETPIPE_SZ isn’t available, assume we’re on Linux < 2.6.35,
           * but ≥ 2.6.11, meaning the pipe capacity is 64KiB. Ignore the
           * possibility of running on Linux < 2.6.11 (where the capacity was
           * the system page size, typically 4KiB) because it’s ancient.
           * See pipe(7). */
          buffer_size = 1024 * 64;
        }
    }

  g_assert (buffer_size > 0);

  total_size = -1;
  /* avoid performance impact of querying total size when it's not needed */
  if (progress_callback)
    {
      g_assert (g_file_info_has_attribute (in_info, G_FILE_ATTRIBUTE_STANDARD_SIZE));
      total_size = g_file_info_get_size (in_info);
    }

  if (total_size == -1)
    total_size = 0;

  offset_in = offset_out = 0;
  res = FALSE;
  while (TRUE)
    {
      long n_read;
      long n_written;

      if (g_cancellable_set_error_if_cancelled (cancellable, error))
        break;

      if (!do_splice (fd_in, &offset_in, buffer[1], NULL, buffer_size, &n_read, error))
        break;

      if (n_read == 0)
        {
          res = TRUE;
          break;
        }

      while (n_read > 0)
        {
          if (g_cancellable_set_error_if_cancelled (cancellable, error))
            goto out;

          if (!do_splice (buffer[0], NULL, fd_out, &offset_out, n_read, &n_written, error))
            goto out;

          n_read -= n_written;
        }

      if (progress_callback)
      
        // Debug -->
        GDateTime *now = g_date_time_new_now_local ();
        gchar *time_str = g_date_time_format (now, "%H:%M:%S:%SS");
        g_date_time_unref (now);

        gint progress = (total_size > 0) ? (100 * offset_in) / total_size : 0;

        g_debug ("[%s] Progress reported by splice: %d%% (%ld of %ld)",
                  time_str,
                  progress,
                  offset_in,
                  total_size);

        g_free (time_str);
        // <-- Debug

          
        progress_callback (offset_in, total_size, progress_callback_data);
    }

  /* Make sure we send full copied size */
  if (progress_callback)
    progress_callback (offset_in, total_size, progress_callback_data);

  if (!g_close (buffer[0], error))
    goto out;
  buffer[0] = -1;
  if (!g_close (buffer[1], error))
    goto out;
  buffer[1] = -1;
 out:
  if (buffer[0] != -1)
    (void) g_close (buffer[0], NULL);
  if (buffer[1] != -1)
    (void) g_close (buffer[1], NULL);

  return res;
}

#endif

Copying a 3GB .iso file from a local SSD to a mounted local USB thumb drive

This outputs:

(nemo:39142): GLib-GIO-DEBUG: 13:46:30.332: [13:46:30] Progress reported by splice: 0% (1048576 of 2960867328)
(nemo:39142): GLib-GIO-DEBUG: 13:46:30.333: [13:46:30] Progress reported by splice: 0% (2097152 of 2960867328)
(nemo:39142): GLib-GIO-DEBUG: 13:46:30.333: [13:46:30] Progress reported by splice: 0% (3145728 of 2960867328)
(nemo:39142): GLib-GIO-DEBUG: 13:46:30.334: [13:46:30] Progress reported by splice: 0% (4194304 of 2960867328)
(nemo:39142): GLib-GIO-DEBUG: 13:46:30.334: [13:46:30] Progress reported by splice: 0% (5242880 of 2960867328)
(nemo:39142): GLib-GIO-DEBUG: 13:46:30.335: [13:46:30] Progress reported by splice: 0% (6291456 of 2960867328)
(nemo:39142): GLib-GIO-DEBUG: 13:46:30.335: [13:46:30] Progress reported by splice: 0% (7340032 of 2960867328)
(nemo:39142): GLib-GIO-DEBUG: 13:46:30.336: [13:46:30] Progress reported by splice: 0% (8388608 of 2960867328)
.
.
.
(nemo:39142): GLib-GIO-DEBUG: 13:46:31.816: [13:46:31] Progress reported by splice: 99% (2958032896 of 2960867328)
(nemo:39142): GLib-GIO-DEBUG: 13:46:31.817: [13:46:31] Progress reported by splice: 99% (2959081472 of 2960867328)
(nemo:39142): GLib-GIO-DEBUG: 13:46:31.817: [13:46:31] Progress reported by splice: 99% (2960130048 of 2960867328)
(nemo:39142): GLib-GIO-DEBUG: 13:46:31.818: [13:46:31] Progress reported by splice: 100% (2960867328 of 2960867328)


(nemo:39142): GLib-GIO-DEBUG: 13:51:56.397: GTask g_io_scheduler_push_job (source object: (nil), source tag: 0x7f1544aa519f) finalized without ever returning (using g_task_return_*()). This potentially indicates a bug in the program.

So splice_stream_with_progress reports 100% after 1-2 seconds using splice. The kernel is
doing the rest under the hood which can easily take minutes to complete. For those who want to see or display write progress, this does not work, the kernel's splice / do_splice are not designed to report progress.
The user get's frustrated and removes the thumb drive with data loss, blaming Linux.

SPLICE_F_MORE
              More data will be coming in a subsequent splice.  This is a
              helpful hint when the fd_out refers to a socket

GIO - gfile.c

#ifdef HAVE_SPLICE

static gboolean
do_splice (int     fd_in,
           loff_t *off_in,
           int     fd_out,
           loff_t *off_out,
           size_t  len,
           long   *bytes_transferd,
           GError **error)
{
  long result;

retry:
  result = splice (fd_in, off_in, fd_out, off_out, len, SPLICE_F_MORE);

  if (result == -1)
    {
      int errsv = errno;

      if (errsv == EINTR)
        goto retry;
      else if (errsv == ENOSYS || errsv == EINVAL || errsv == EOPNOTSUPP)
        g_set_error_literal (error, G_IO_ERROR, G_IO_ERROR_NOT_SUPPORTED,
                             _("Splice not supported"));
      else
        g_set_error (error, G_IO_ERROR,
                     g_io_error_from_errno (errsv),
                     _("Error splicing file: %s"),
                     g_strerror (errsv));

      return FALSE;
    }

  *bytes_transferd = result;
  return TRUE;
}

#endif

Proposal

Regular files when copied to a mounted consumer device are copied synchronously so that the Desktop user can see progress.

(is_regular_gfile_and_dest_is_consumer_usb_blk_device)

This should effectively solve issues 1644, 3465, 3526, 3677.