y500 / libtorrent

Automatically exported from code.google.com/p/libtorrent
0 stars 0 forks source link

Torrent status: error Invalid argument: #582

Open GoogleCodeExporter opened 8 years ago

GoogleCodeExporter commented 8 years ago
This happens time to time when downloading. It runs on android devices and give 
torrent status: error Invalid argument: /storage/emulated/0/test/download

session stop downloading and only up loading with 0.xxkB/s.

It seems external storage issue. But when log in to device, it external SDcard 
just fine. Didn't see any issues.

Original issue reported on code.google.com by ygao....@gmail.com on 14 Feb 2014 at 3:32

GoogleCodeExporter commented 8 years ago
SDcard become read-only. It crashed by downloading.

Original comment by ygao....@gmail.com on 14 Feb 2014 at 3:53

GoogleCodeExporter commented 8 years ago
is strace available on android? if so, it might be helpful to know exactly 
which operation that failed with EINVAL.

Original comment by arvid.no...@gmail.com on 14 Feb 2014 at 5:00

GoogleCodeExporter commented 8 years ago
[deleted comment]
GoogleCodeExporter commented 8 years ago
[deleted comment]
GoogleCodeExporter commented 8 years ago
[deleted comment]
GoogleCodeExporter commented 8 years ago
I would have expected to see at least one system call fail with EINVAL. can you 
grep for that? if you find it, please post the surrounding log. EAGAIN is 
normal, it just means there's no data on the socket.

Do you get this problem specifically when downloading files > 2GiB? or > 4GiB?

Original comment by arvid.no...@gmail.com on 15 Feb 2014 at 2:48

GoogleCodeExporter commented 8 years ago
Still test with less size than 4GB. But this happens with large than 5GB. But I 
remember that I met the same issue with large than 2GB file a few days ago. 

fstat64(37, {st_mode=S_IFREG|0660, st_size=716800, ...}) = 0
pread(37, "\0\0\2\20\0\0\0\257\0\0\0\0\0\0\0\0", 16, 104154897828) = 16
fstat64(37, {st_mode=S_IFREG|0660, st_size=716800, ...}) = 0
access("/data/data/net.video2cloud.video2MP/databases/video2MP-wal", F_OK) = -1 
ENOENT (No such file or directory)
fstat64(37, {st_mode=S_IFREG|0660, st_size=716800, ...}) = 0
fcntl64(37, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
gettimeofday({1392418950, 498487}, NULL) = 0
munmap(0x60d43000, 2097152)             = 0
close(60)                               = 0
gettimeofday({1392418950, 500284}, NULL) = 0
gettimeofday({1392418950, 500606}, NULL) = 0
open("/dev/ashmem", O_RDWR|O_LARGEFILE) = 60
ioctl(60, 0x41007701, 0xbeb9b4c4)       = 0
ioctl(60, 0x40047703, 0x200000)         = 0
ioctl(60, 0x40047705, 0x3)              = 0
mmap2(NULL, 2097152, PROT_READ|PROT_WRITE, MAP_SHARED, 60, 0) = 0x60d43000
ioctl(60, 0x40047705, 0x1)              = 0
gettimeofday({1392418950, 502368}, NULL) = 0
fcntl64(37, F_SETLK, {type=F_RDLCK, whence=SEEK_SET, start=1073741824, len=1}) 
= 0
fcntl64(37, F_SETLK, {type=F_RDLCK, whence=SEEK_SET, start=1073741826, 
len=510}) = 0
fcntl64(37, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=1073741824, len=1}) 
= 0
access("/data/data/net.video2cloud.video2MP/databases/video2MP-journal", F_OK) 
= 0
stat64("/data/data/net.video2cloud.video2MP/databases/video2MP-journal", 
{st_mode=S_IFREG|0600, st_size=33344, ...}) = 0
fcntl64(37, F_GETLK, {type=F_UNLCK, whence=SEEK_SET, start=1073741825, len=1, 
pid=0}) = 0
fstat64(37, {st_mode=S_IFREG|0660, st_size=716800, ...}) = 0
stat64("/data/data/net.video2cloud.video2MP/databases/video2MP", 
{st_mode=S_IFREG|0660, st_size=716800, ...}) = 0
umask(0)                                = 077
open("/data/data/net.video2cloud.video2MP/databases/video2MP-journal", 
O_RDONLY|O_LARGEFILE) = 62
umask(077)                              = 0
fchown32(62, 10008, 10008)              = 0
fcntl64(62, F_GETFD)                    = 0
fcntl64(62, F_SETFD, FD_CLOEXEC)        = 0
pread(62, "\0", 1, 1075682724)          = 1
close(62)                               = 0
fstat64(37, {st_mode=S_IFREG|0660, st_size=716800, ...}) = 0
pread(37, "\0\0\2\20\0\0\0\257\0\0\0\0\0\0\0\0", 16, 104154897828) = 16
fstat64(37, {st_mode=S_IFREG|0660, st_size=716800, ...}) = 0
access("/data/data/net.video2cloud.video2MP/databases/video2MP-wal", F_OK) = -1 
ENOENT (No such file or directory)
fstat64(37, {st_mode=S_IFREG|0660, st_size=716800, ...}) = 0
fcntl64(37, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
gettimeofday({1392418950, 509456}, NULL) = 0
munmap(0x60d43000, 2097152)             = 0
close(60)                               = 0
clock_gettime(CLOCK_MONOTONIC, {6738, 433462007}) = 0
mmap2(NULL, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 
0x5cc61000
madvise(0x5cc61000, 16384, 0xc /* MADV_??? */) = -1 EINVAL (Invalid argument)
mmap2(NULL, 1048576, PROT_READ|PROT_WRITE, 
MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x60d43000
madvise(0x60d43000, 1048576, 0xc /* MADV_??? */) = -1 EINVAL (Invalid argument)
mprotect(0x60d43000, 4096, PROT_NONE)   = 0
clone(child_stack=0x60e42ef8, 
flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLO
NE_DETACHED) = 4585
futex(0x60e42f00, 0x81 /* FUTEX_??? */, 1) = 1
futex(0x408c54bc, 0x81 /* FUTEX_??? */, 2147483647) = 1
futex(0x408c54b8, 0x81 /* FUTEX_??? */, 1) = 1
pread(33, "PK\3\4\n\0\0\0\0\0\374YMD\342\240r\365\177\2\0\0\177\2"..., 30, 
4910762527031296) = 30
mmap2(NULL, 1295, PROT_READ, MAP_SHARED, 33, 0x117) = 0x5a6b6000
sigprocmask(SIG_BLOCK, [], [QUIT USR1 PIPE]) = 0
sigprocmask(SIG_BLOCK, [], [QUIT USR1 PIPE]) = 0
sigprocmask(SIG_BLOCK, [], [QUIT USR1 PIPE]) = 0
sigprocmask(SIG_BLOCK, [], [QUIT USR1 PIPE]) = 0
munmap(0x5a6b6000, 1295)                = 0
getuid32()                              = 10008
writev(5, [{"Fu\0\0", 4}, {"\3\2\0\0\0\0\0\2.\0\0\0net.video2cloud.vide"..., 
59}], 2) = 63
getpid()                                = 2512
gettid()                                = 2512
clock_gettime(CLOCK_MONOTONIC, {6738, 490253008}) = 0
ioctl(9, 0xc0186201, 0xbeb9b4e0)        = 0
ioctl(9, 0xc0186201, 0xbeb9b4e0)        = 0
clock_gettime(CLOCK_MONOTONIC, {6738, 491040008}) = 0
getpid()                                = 2512
getuid32()                              = 10008
epoll_wait(0x1f, 0xbeb9b4e0, 0x10, 0)   = 1
recvfrom(41, "nysv\0\0\0\0oJ\325\330 \6\0\0\256q\3\0\0\0\0\0", 24, 
MSG_DONTWAIT, NULL, NULL) = 24
recvfrom(41, 0xbeb9ab08, 24, 64, 0, 0)  = -1 EAGAIN (Resource temporarily 
unavailable)
clock_gettime(CLOCK_MONOTONIC, {6738, 492112008}) = 0
clock_gettime(CLOCK_MONOTONIC, {6738, 492304007}) = 0
getpid()                                = 2512
getuid32()                              = 10008
epoll_wait(0x1f, 0xbeb9b4e0, 0x10, 0)   = 0
clock_gettime(CLOCK_MONOTONIC, {6738, 492887007}) = 0
mprotect(0x5f1e9000, 360, PROT_READ|PROT_WRITE|PROT_EXEC) = 0
syscall_983042(0x5f1e9164, 0x5f1e9168, 0, 0xfff, 0x408c5680, 0x5f1e9164, 
0x5f2151c1, 0xf0002, 0, 0x5f1e9168, 0xf82cf02c, 0x40bf4e48, 0, 0xbeb9b740, 
0x4089937b, 0x401dafb4, 0x40000010, 0x5f1e9164, 0, 0, 0xc764, 0, 0, 0, 0, 0, 0, 
0, 0, 0, 0, 0) = 0
mprotect(0x5f1e9000, 360, PROT_READ|PROT_EXEC) = 0
futex(0x408c56bc, 0x81 /* FUTEX_??? */, 1) = 1
futex(0x408c56b4, 0x81 /* FUTEX_??? */, 1) = 1
futex(0x408c56bc, 0x81 /* FUTEX_??? */, 1) = 0
futex(0x408c56b4, 0x81 /* FUTEX_??? */, 1) = 1
clock_gettime(CLOCK_MONOTONIC, {6738, 494614007}) = 0
getpid()                                = 2512
gettid()                                = 2512
clock_gettime(CLOCK_MONOTONIC, {6738, 496445007}) = 0
ioctl(9, 0xc0186201, 0xbeb9b4e0)        = 0
futex(0x40256064, 0x80 /* FUTEX_??? */, 2) = -1 EAGAIN (Resource temporarily 
unavailable)

Original comment by ygao....@gmail.com on 15 Feb 2014 at 3:41

GoogleCodeExporter commented 8 years ago
Obviously, madvice is the reason for this.
The only clue is void file::hint_read(size_type file_offset, int len)
But, in my build there aren't defined for  POSIX_FADV_WILLNEED and  F_RDADVISE.
So, it could be called by indirectly from boost?
How to trace where the call from?

Original comment by ygao....@gmail.com on 15 Feb 2014 at 4:51

GoogleCodeExporter commented 8 years ago
well.. the posix_fadvise() call ignores errors, so I wouldn't expect that to 
bubble up to libtorrent. You don't see any other calls fail with EINVAL?
I can't find any calls in boost to madvise either (and I wouldn't really expect 
any). It's probably part of some libc function.

Original comment by arvid.no...@gmail.com on 15 Feb 2014 at 6:14

GoogleCodeExporter commented 8 years ago
btw. which version of libtorrent are you using?

Original comment by arvid.no...@gmail.com on 15 Feb 2014 at 6:22

GoogleCodeExporter commented 8 years ago
0.16.12

#0  libtorrent::storage_interface::set_error (this=0x5c4f2b80, file=..., 
ec=...) at storage.cpp:218
#1  0x5e37555e in libtorrent::default_storage::readwritev (this=0x5c4f2b80, 
bufs=<optimized out>, slot=<optimized out>, offset=<optimized out>, num_bufs=1, 
op=...) at storage.cpp:1252
#2  0x5e375948 in libtorrent::default_storage::writev (this=<optimized out>, 
bufs=<optimized out>, slot=<optimized out>, offset=<optimized out>, num_bufs=1, 
flags=32) at storage.cpp:966
#3  0x5e37a630 in libtorrent::piece_manager::write_impl (this=0x5c4ed798, 
bufs=<optimized out>, piece_index=553, offset=0, num_bufs=1) at storage.cpp:1799
#4  0x5e41dc0e in libtorrent::disk_io_thread::flush_range (this=0x5c6a9978, 
p=..., start=0, end=1, l=...) at disk_io_thread.cpp:607
#5  0x5e41f9d4 in libtorrent::disk_io_thread::flush_cache_blocks 
(this=0x5c6a9978, l=..., blocks=27, ignore=..., options=0) at 
disk_io_thread.cpp:543
#6  0x5e424036 in libtorrent::disk_io_thread::thread_fun (this=0x5c6a9978) at 
disk_io_thread.cpp:2161
#7  0x5e4251e6 in operator() (p=<optimized out>, this=<optimized out>) at 
/home/mike/proj/streaming/moviett/vlc/contrib/android/torrent/boost/build/includ
e/boost/bind/mem_fn_template.hpp:49
#8  operator()<boost::_mfi::mf0<void, libtorrent::disk_io_thread>, 
boost::_bi::list0> (f=<optimized out>, this=<optimized out>, a=<optimized out>) 
at 
/home/mike/proj/streaming/moviett/vlc/contrib/android/torrent/boost/build/includ
e/boost/bind/bind.hpp:253
#9  operator() (this=<optimized out>) at 
/home/mike/proj/streaming/moviett/vlc/contrib/android/torrent/boost/build/includ
e/boost/bind/bind_template.hpp:20
#10 boost::asio::detail::posix_thread::func<boost::_bi::bind_t<void, 
boost::_mfi::mf0<void, libtorrent::disk_io_thread>, 
boost::_bi::list1<boost::_bi::value<libtorrent::disk_io_thread*> > > >::run 
(this=<optimized out>) at 
/home/mike/proj/streaming/moviett/vlc/contrib/android/torrent/boost/build/includ
e/boost/asio/detail/posix_thread.hpp:82
#11 0x5e31f586 in boost::asio::detail::boost_asio_detail_posix_thread_function 
(arg=<optimized out>) at 
/home/mike/proj/streaming/moviett/vlc/contrib/android/torrent/boost/build/includ
e/boost/asio/detail/impl/posix_thread.ipp:64
#12 0x401d13dc in __thread_entry () from 
/home/mike/proj/streaming/moviett/video2M/obj/local/armeabi-v7a/libc.so
#13 0x401d0ac8 in pthread_create () from 
/home/mike/proj/streaming/moviett/video2M/obj/local/armeabi-v7a/libc.so
#14 0x00000000 in ?? ()

Original comment by ygao....@gmail.com on 16 Feb 2014 at 2:18

GoogleCodeExporter commented 8 years ago
That narrows it down to either the pwrite() operation, or one of the operations 
in set_size().

I don't think unbuffered mode is enabled by default. If you're not using that 
(i.e. disable_os_cache in settings) then it's the pwrite that's failing.

If you're downloading a torrent whose piece size is 4 MiB, then piece 553 would 
bring it over the 2 GiB limit some older filesystems have. Is the piece size of 
this torrent 4 MiB?

Is the filesystem on your sdcard FAT32?

If so, you're probably hitting the limit, and I'm open to suggestions on how 
libtorrent could deal with that. Split up large files into multiple parts?

Original comment by arvid.no...@gmail.com on 16 Feb 2014 at 4:18

GoogleCodeExporter commented 8 years ago
You are right. number of pieces: 1444, piece length: 4194304
But the file system is ext4: /dev/block/mmcblk0p8 /data ext4 
And this error can not be ignored (I commented out set_error there to test). 
The app will crash after a while.

libtorrent::disk_buffer_pool::free_buffer_impl(char*, 
boost::asio::detail::scoped_lock<boost::asio::detail::posix_mutex>&)+78

libtorrent::disk_buffer_pool::free_buffer(char*)+30

Original comment by ygao....@gmail.com on 16 Feb 2014 at 3:45

GoogleCodeExporter commented 8 years ago
It also has the same issue with 2G GiB file.

Original comment by ygao....@gmail.com on 16 Feb 2014 at 3:46

GoogleCodeExporter commented 8 years ago
How to let pieces after e.g, 533 goes to different file in libtorrent. Thanks!

Original comment by ygao....@gmail.com on 16 Feb 2014 at 3:56

GoogleCodeExporter commented 8 years ago
And, this happens when the maximum piece number coming is 241 and total size is 
less than 900MiB.

Original comment by ygao....@gmail.com on 16 Feb 2014 at 4:03

GoogleCodeExporter commented 8 years ago
bytes_transferred = (int)((*file_handle).*op.regular_op)(adjusted_offset
                    , tmp_bufs, num_tmp_bufs, ec);
if (ec)
{
here =>    set_error(combine_path(m_save_path, files().file_path(*file_iter)), 
ec);
    return -1;
}
TORRENT_ASSERT(bytes_transferred <= bufs_size(tmp_bufs, num_tmp_bufs));

Original comment by ygao....@gmail.com on 16 Feb 2014 at 4:33

GoogleCodeExporter commented 8 years ago
it just occurred to me that android's libc / system call stubs don't support 
large files. The kernel does though.

What this means is that the filesystem doesn't necessarily matter, it's the 
layer between libtorrent and the kernel that's the limitation. It's possible to 
work around this by providing custom system call stubs via the syscall() 
function. The android headers should provide the system call number for seek, 
pread and pwrite and possibly preadv and pwritev if available. Providing those 
stubs to make the correct system calls to the 64-bit aware functions would 
solve any problems associated with a 2 GiB or 4 GiB limit. (I'm not sure which 
one it is, different systems and filesystems sometimes have a 4 GiB limit, if 
they use uint32 and some have a 2 GiB limit if they use int32, i.e. signed 
ints).

However, that still leaves the issue of trying to write a 900 MiB file 
unexplained. I'm inclined to believe that may be a different issue though, or 
possible some cascading issue

Original comment by arvid.no...@gmail.com on 16 Feb 2014 at 9:40