libtorrent icon indicating copy to clipboard operation
libtorrent copied to clipboard

moving files after downloading

Open Aleksman4o opened this issue 3 years ago • 12 comments

Please provide the following information

libtorrent version (or branch): 2.0.7 with qbittorrent-nox from master

platform/architecture: linux 5.18 x64

compiler and compiler version:

I'm downloading files to temp folder on ssd and after that torrents moving to another hdd. If there are one file in a torrent, it's moving normally. When there are many folders with files - some of them copying and some not. After restarting qbittorrent moving process repeating and stops on the same files. i'm see this on a file modified time. This problem started about couple a weeks ago, with libtorrent 1.2.17 it's not exists. Problem also exists with libtorrent-rasterbar-2 when simply moving torrent from one disk to another.

Aleksman4o avatar Jul 30 '22 14:07 Aleksman4o

When there are many folders with files - some of them copying and some not. After restarting qbittorrent moving process repeating and stops on the same files. i'm see this on a file modified time.

Are there any error messages in the qBittorrent log related to moving files?

glassez avatar Jul 30 '22 22:07 glassez

There are no logs in qbit logs folder. May be because of sqlite database for torrents.

Aleksman4o avatar Jul 30 '22 23:07 Aleksman4o

I've found logs in old ~/.local/data folders :) That's part of errored files:

(W) 2022-07-26T21:45:10 - Не удалось переместить торрент. Торрент: «Starship Troopers 2». Источник: «/mnt/HRAN10TB8/Хранитель/Зарубежное кино (HD Video)». Назначение: «/mnt/HRAN12TB10/Хранитель/Зарубежное кино (HD Video)». Причина: «Starship Troopers 2 storage move failed. file_rename (/mnt/HRAN10TB8/Хранитель/Зарубежное кино (HD Video)/Starship Troopers 2/AACS/DUPLICATE/ContentRevocation.lst): Нет такого устройства или адреса»

(W) 2022-07-27T02:12:13 - Не удалось переместить торрент. Торрент: «DISCLOSURE_BD_BLUEBIRD». Источник: «/mnt/HRAN10TB8/Хранитель/Зарубежное кино (HD Video)». Назначение: «/mnt/HRAN12TB10/Хранитель/Зарубежное кино (HD Video)». Причина: «DISCLOSURE_BD_BLUEBIRD storage move failed. file_rename (/mnt/HRAN10TB8/Хранитель/Зарубежное кино (HD Video)/DISCLOSURE_BD_BLUEBIRD/ANY!/ContentRevocation.lst): Нет такого устройства или адреса»

(W) 2022-07-26T14:50:51 - Не удалось переместить торрент. Торрент: «G.I.JOE_2_BD_EUR». Источник: «/mnt/HRAN10TB8/Хранитель/Зарубежное кино (HD Video)». Назначение: «/mnt/HRAN12TB10/Хранитель/Зарубежное кино (HD Video)». Причина: «G.I.JOE_2_BD_EUR storage move failed. file_rename (/mnt/HRAN10TB8/Хранитель/Зарубежное кино (HD Video)/G.I.JOE_2_BD_EUR/FAB!/DUPLICATE/ContentRevocation.lst): Нет такого устройства или адреса»

(W) 2022-07-28T04:29:48 - Не удалось переместить торрент. Торрент: «Deep Purple». Источник: «/mnt/ssd_cache/.downloading_temp». Назначение: «/mnt/HRAN6TB4/Хранитель/Апмиксы - Даунмиксы». Причина: «Deep Purple storage move failed. file_rename (/mnt/ssd_cache/.downloading_temp/Deep Purple/07-Deep Purple - Stormbringer DTS 5.1 1974/(03) [Deep Purple] Holy Man.wav): Нет такого устройства или адреса»

(W) 2022-07-28T04:22:48 - Не удалось переместить торрент. Торрент: «Billy Joel - Glass Houses (1980) [MFSL 2012] (SACD-ISO)». Источник: «/mnt/ssd_cache/.downloading_temp». Назначение: «/mnt/HRAN8TB7/Хранитель/Рок-музыка (Hi-Res stereo)». Причина: «Billy Joel - Glass Houses (1980) [MFSL 2012] (SACD-ISO) storage move failed. file_rename (/mnt/ssd_cache/.downloading_temp/Billy Joel - Glass Houses (1980) [MFSL 2012] (SACD-ISO)/Mobile Fidelity Sound Lab - Glass Houses.iso): Нет такого устройства или адреса»

(W) 2022-07-28T04:25:04 - Не удалось переместить торрент. Торрент: «John Lennon - Mind Games (1973) [SACD] (2014 SHM-SACD ISO)». Источник: «/mnt/ssd_cache/.downloading». Назначение: «/mnt/HRAN8TB7/Хранитель/Рок-музыка (Hi-Res stereo)». Причина: «John Lennon - Mind Games (1973) [SACD] (2014 SHM-SACD ISO) storage move failed. file_rename (/mnt/ssd_cache/.downloading/John Lennon - Mind Games (1973) [SACD] (2014 SHM-SACD ISO)/Mind Games.iso): Нет такого устройства или адреса»

Aleksman4o avatar Aug 02 '22 10:08 Aleksman4o

the error message translates to: "No such device or address".

@Aleksman4o are the paths correct?

arvidn avatar Aug 21 '22 18:08 arvidn

Yes, with libtorrent 1.2.17 files were moved correctly.

Aleksman4o avatar Aug 21 '22 18:08 Aleksman4o

I'm seeing this, potentially the same, issue as well with Deluge. Our environment is Docker and two different NFSv4 mounts (one mount for in-progress DLs and one for completed DLs). Upon completion Deluge is configured to move from the scratch mount to a permanent location.

Working Docker image: linuxserver/deluge:2.0.5-0202202181752ubuntu20.04.1-ls140 (image ID ece15b2c6382)

Non-working image: linuxserver/deluge:latest (image ID dcbf5bbe4925)

The working image is Ubuntu 20.04.3 LTS:

root@6ed0002357b2:/# apt list | grep -i libtorrent
libtorrent-rasterbar9/now 1.1.13-1.1build2 amd64 [installed,local]
python3-libtorrent/now 1.1.13-1.1build2 amd64 [installed,local]
root@6ed0002357b2:/#

The non-working image is Alpine Edge:

root@868165f4a055:/# apk list | grep libtorr
libtorrent-rasterbar-2.0.7-r2 x86_64 {libtorrent-rasterbar} (BSD-3-Clause) [installed]
py3-libtorrent-rasterbar-2.0.7-r2 x86_64 {libtorrent-rasterbar} (BSD-3-Clause) [installed]
root@868165f4a055:/

Docker run command: docker run -it --rm --name torrent -p 8112:8112 -e "TZ=America/Chicago" -e "PUID=21023" -e "PGID=30502" -e "DELUGE_LOGLEVEL=debug" -v /nas/docker/deluge:/config -v /nas/scratch/deluge:/downloads -v /nas/media:/complete linuxserver/deluge:$IMAGE_TAG

Torrent: magnet:?xt=urn:btih:c4769d7000244e4cae9c054a83e38f168bf4f69f&dn=archlinux-2022.09.03-x86_64.iso

Logs observed:

15:47:29 [DEBUG   ][deluge.core.rpcserver         :318 ] RPC dispatch core.get_torrents_status
15:47:29 [DEBUG   ][deluge.core.rpcserver         :318 ] RPC dispatch core.get_filter_tree
15:47:29 [DEBUG   ][deluge.core.rpcserver         :318 ] RPC dispatch core.get_session_status
15:47:29 [DEBUG   ][deluge.core.rpcserver         :318 ] RPC dispatch core.get_free_space
15:47:29 [DEBUG   ][deluge.core.rpcserver         :318 ] RPC dispatch core.get_external_ip
15:47:29 [DEBUG   ][deluge.core.rpcserver         :318 ] RPC dispatch core.get_torrent_status
15:47:29 [DEBUG   ][deluge.core.alertmanager      :108 ] Alerts queued: 5
15:47:29 [DEBUG   ][deluge.core.alertmanager      :120 ] state_update_alert: state updates for 1 torrents
15:47:29 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: state_update_alert
15:47:29 [DEBUG   ][deluge.core.alertmanager      :120 ] file_completed_alert: archlinux-2022.09.03-x86_64.iso: file 0 finished downloading
15:47:29 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: file_completed_alert
15:47:29 [DEBUG   ][deluge.core.alertmanager      :120 ] state_changed_alert: archlinux-2022.09.03-x86_64.iso: state changed to: finished
15:47:29 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: state_changed_alert
15:47:29 [DEBUG   ][deluge.core.alertmanager      :120 ] torrent_finished_alert: archlinux-2022.09.03-x86_64.iso torrent finished downloading
15:47:29 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: torrent_finished_alert
15:47:29 [DEBUG   ][deluge.core.alertmanager      :120 ] state_changed_alert: archlinux-2022.09.03-x86_64.iso: state changed to: seeding
15:47:29 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: state_changed_alert
15:47:29 [DEBUG   ][deluge.core.rpcserver         :547 ] intevents: {4: ['ConfigValueChangedEvent', 'PluginEnabledEvent', 'PluginDisabledEvent', 'TorrentStateChangedEvent', 'TorrentRemovedEvent', 'TorrentAddedEvent']}
15:47:29 [DEBUG   ][deluge.core.rpcserver         :547 ] intevents: {4: ['ConfigValueChangedEvent', 'PluginEnabledEvent', 'PluginDisabledEvent', 'TorrentStateChangedEvent', 'TorrentRemovedEvent', 'TorrentAddedEvent']}
15:47:29 [DEBUG   ][deluge.core.rpcserver         :551 ] Emit Event: TorrentStateChangedEvent ['c4769d7000244e4cae9c054a83e38f168bf4f69f', 'Seeding']
15:47:29 [DEBUG   ][deluge.core.torrent           :678 ] State from lt was: seeding | Session is paused: False
Torrent state set from "Downloading" to "Seeding" (c4769d7000244e4cae9c054a83e38f168bf4f69f)
15:47:29 [DEBUG   ][deluge.core.torrentmanager    :1280] Finished c4769d7000244e4cae9c054a83e38f168bf4f69f
15:47:29 [DEBUG   ][deluge.core.torrentmanager    :1281] Torrent settings: is_finished: False, total_download: 843004996, move_completed: True, move_path: /complete
15:47:29 [DEBUG   ][deluge.core.torrent           :678 ] State from lt was: seeding | Session is paused: False
Torrent state set from "Seeding" to "Seeding" (c4769d7000244e4cae9c054a83e38f168bf4f69f)
15:47:29 [DEBUG   ][deluge.core.rpcserver         :547 ] intevents: {4: ['ConfigValueChangedEvent', 'PluginEnabledEvent', 'PluginDisabledEvent', 'TorrentStateChangedEvent', 'TorrentRemovedEvent', 'TorrentAddedEvent']}
15:47:29 [DEBUG   ][deluge.core.rpcserver         :551 ] Emit Event: TorrentStateChangedEvent ['c4769d7000244e4cae9c054a83e38f168bf4f69f', 'Moving']
15:47:29 [DEBUG   ][deluge.core.torrent           :678 ] State from lt was: seeding | Session is paused: False
Torrent state set from "Seeding" to "Moving" (c4769d7000244e4cae9c054a83e38f168bf4f69f)
15:47:29 [DEBUG   ][deluge.core.torrent           :1330] Requesting save_resume_data for torrent: c4769d7000244e4cae9c054a83e38f168bf4f69f
15:47:29 [DEBUG   ][deluge.core.torrent           :678 ] State from lt was: seeding | Session is paused: False
Torrent state set from "Moving" to "Moving" (c4769d7000244e4cae9c054a83e38f168bf4f69f)
15:47:30 [DEBUG   ][deluge.core.alertmanager      :108 ] Alerts queued: 4
15:47:30 [DEBUG   ][deluge.core.alertmanager      :120 ] save_resume_data_alert: archlinux-2022.09.03-x86_64.iso resume data generated
15:47:30 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: save_resume_data_alert
15:47:30 [DEBUG   ][deluge.core.alertmanager      :120 ] cache_flushed_alert: archlinux-2022.09.03-x86_64.iso
15:47:30 [DEBUG   ][deluge.core.alertmanager      :120 ] storage_moved_failed_alert: archlinux-2022.09.03-x86_64.iso storage move failed. file_rename (/downloads/archlinux-2022.09.03-x86_64.iso): Not supported
15:47:30 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: storage_moved_failed_alert
15:47:30 [DEBUG   ][deluge.core.alertmanager      :120 ] session_stats_alert: session stats (291 values): 0, 515, 4, 0, 21, 0, 0, 0, 0, 2, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 179, 0, 0, 178, 1, 19, 99, 234, 3480, 0, 0, 214, 0, 318, 158, 0, 0, 9172, 6134, 32, 1159, 379, 30, 0, 0, 0, 389, 0, 0, 452, 92538, 60, 0, 285, 4, 108630, 119251, 318, 0, 0, 91141, 2, 0, 23321, 33, 166, 0, 0, 2, 8, 0, 51425, 0, 90, 0, 0, 0, 0, 0, 92, 0, 5, 106, 78, 81, 93, 70, 111777, 164, 52936, 139, 47, 92, 0, 0, 11, 0, 0, 92, 0, 5, 55, 0, 0, 0, 63697, 0, 63697, 149217, 50837, 1626553, 0, 50837, 50837, 0, 0, 23575791, 5772161, 29347952, 4325376, 0, 2291980, 0, 3047424, 476888, 0, 2021491, 28928972, 0, 843036109, 843872951, 28898916, 0, 0, 10141668, 297, 0, 639, 1, 89135, 67540, 0, 1, 1, 0, 2, 628, 0, 8, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1064, 510364, 198108, 0, 824, 129, 37202, 479019, 37512, 0, 233, 90191, 20156, 5656, 1458, 945, 749, 86, 10, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 667, 248, 110, 321, 308, 813, 6025, 44045, 21152, 20983, 11532, 4856, 1057, 297, 391, 524, 51, 5, 0, 33, 0, 0, 1, 0, 0, 0, 0, 13, 0, 0, 1, 0, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 14, 0, 90, 0, 0, 13, 0, 0, 0, 0, 0, 0, 0, 0, 10, 0, 0, 50, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 200, 89, 0, 0, 0, 0, 3, 1, 0, 0, 0, 0, 0, 0, 1, 48, 0, 0, 2, 0
15:47:30 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: session_stats_alert
15:47:30 [WARNING ][deluge.core.torrentmanager    :1433] on_alert_storage_moved_failed: archlinux-2022.09.03-x86_64.iso storage move failed. file_rename (/downloads/archlinux-2022.09.03-x86_64.iso): Not supported
15:47:30 [DEBUG   ][deluge.core.torrentmanager    :1131] Creating the temporary file: /config/state/torrents.fastresume.tmp
15:47:30 [DEBUG   ][deluge.core.rpcserver         :547 ] intevents: {4: ['ConfigValueChangedEvent', 'PluginEnabledEvent', 'PluginDisabledEvent', 'TorrentStateChangedEvent', 'TorrentRemovedEvent', 'TorrentAddedEvent']}
15:47:30 [DEBUG   ][deluge.core.rpcserver         :551 ] Emit Event: TorrentStateChangedEvent ['c4769d7000244e4cae9c054a83e38f168bf4f69f', 'Error']
15:47:30 [DEBUG   ][deluge.core.torrent           :678 ] State from lt was: seeding | Session is paused: False
Torrent state set from "Moving" to "Error" (c4769d7000244e4cae9c054a83e38f168bf4f69f)
15:47:30 [DEBUG   ][deluge.core.torrent           :687 ] Torrent Error state message: Failed to move download folder: Not supported
15:47:30 [DEBUG   ][deluge.core.rpcserver         :547 ] intevents: {4: ['ConfigValueChangedEvent', 'PluginEnabledEvent', 'PluginDisabledEvent', 'TorrentStateChangedEvent', 'TorrentRemovedEvent', 'TorrentAddedEvent']}
15:47:30 [DEBUG   ][deluge.core.torrentmanager    :1141] Creating backup of torrents.fastresume at: /config/state/torrents.fastresume.bak
15:47:30 [DEBUG   ][deluge.core.torrentmanager    :1151] Saving torrents.fastresume to: /config/state/torrents.fastresume
15:47:30 [DEBUG   ][deluge.core.alertmanager      :108 ] Alerts queued: 1
15:47:30 [DEBUG   ][deluge.core.alertmanager      :120 ] torrent_paused_alert: archlinux-2022.09.03-x86_64.iso paused
15:47:30 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: torrent_paused_alert
15:47:30 [DEBUG   ][deluge.core.torrent           :678 ] State from lt was: seeding | Session is paused: False
Torrent state set from "Error" to "Error" (c4769d7000244e4cae9c054a83e38f168bf4f69f)
15:47:30 [DEBUG   ][deluge.core.torrent           :687 ] Torrent Error state message: Failed to move download folder: Not supported
15:47:30 [DEBUG   ][deluge.core.torrent           :1330] Requesting save_resume_data for torrent: c4769d7000244e4cae9c054a83e38f168bf4f69f
15:47:30 [DEBUG   ][deluge.core.torrentmanager    :1131] Creating the temporary file: /config/state/torrents.fastresume.tmp
15:47:30 [DEBUG   ][deluge.core.torrentmanager    :1141] Creating backup of torrents.fastresume at: /config/state/torrents.fastresume.bak
15:47:30 [DEBUG   ][deluge.core.torrentmanager    :1151] Saving torrents.fastresume to: /config/state/torrents.fastresume
15:47:30 [DEBUG   ][deluge.core.alertmanager      :108 ] Alerts queued: 1

Expected behavior: Completed torrent is moved from scratch to completed downloads and begins seeding. Observed behavior: Torrent completes and immediately reports an Error state. Torrent is neither moved from scratch location nor begins seeding.

ITestInProd avatar Sep 14 '22 00:09 ITestInProd

a relevant log line is:

storage_moved_failed_alert: archlinux-2022.09.03-x86_64.iso storage move failed. file_rename (/downloads/archlinux-2022.09.03-x86_64.iso): Not supported

the file_rename operation is wrong, it's the copy_file() that's failing.

Any chance you could give this patch a try? https://github.com/arvidn/libtorrent/pull/7077

arvidn avatar Sep 14 '22 08:09 arvidn

my theory is that NFS fails with ENOTSUP when calling copy_file_range(). This case is currently not handled by falling back on a traditional read-write loop to copy the bytes. The patch above makes it fall back.

It's quite unfortunate though, NFS is a perfect example of where you really can have a performance benefit of supporting copy_file_range() (which would allow server-side copy, rather than reading over the network followed by writing back over the network).

arvidn avatar Sep 15 '22 09:09 arvidn

I think I compiled it correctly with against that patch (excluding the Python bindings).

Debug logs upon download completion and move attempt:

08:04:16 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: session_stats_alert
08:04:16 [DEBUG   ][deluge.core.rpcserver         :318 ] RPC dispatch core.get_torrents_status
08:04:16 [DEBUG   ][deluge.core.rpcserver         :318 ] RPC dispatch core.get_filter_tree
08:04:16 [DEBUG   ][deluge.core.rpcserver         :318 ] RPC dispatch core.get_session_status
08:04:16 [DEBUG   ][deluge.core.rpcserver         :318 ] RPC dispatch core.get_free_space
08:04:16 [DEBUG   ][deluge.core.rpcserver         :318 ] RPC dispatch core.get_external_ip
08:04:16 [DEBUG   ][deluge.core.rpcserver         :318 ] RPC dispatch core.get_torrent_status
08:04:16 [DEBUG   ][deluge.core.alertmanager      :108 ] Alerts queued: 6
08:04:16 [DEBUG   ][deluge.core.alertmanager      :120 ] state_update_alert: state updates for 1 torrents
08:04:16 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: state_update_alert
08:04:16 [DEBUG   ][deluge.core.alertmanager      :120 ] file_completed_alert: archlinux-2022.09.03-x86_64.iso: file 0 finished downloading
08:04:16 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: file_completed_alert
08:04:16 [DEBUG   ][deluge.core.alertmanager      :120 ] state_changed_alert: archlinux-2022.09.03-x86_64.iso: state changed to: finished
08:04:16 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: state_changed_alert
08:04:16 [DEBUG   ][deluge.core.alertmanager      :120 ] torrent_finished_alert: archlinux-2022.09.03-x86_64.iso torrent finished downloading
08:04:16 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: torrent_finished_alert
08:04:16 [DEBUG   ][deluge.core.alertmanager      :120 ] state_changed_alert: archlinux-2022.09.03-x86_64.iso: state changed to: seeding
08:04:16 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: state_changed_alert
08:04:16 [DEBUG   ][deluge.core.alertmanager      :120 ] session_stats_alert: session stats (291 values): 1, 1650, 32, 3, 77, 0, 0, 0, 0, 6, 0, 0, 0, 0, 0, 54, 0, 0, 0, 0, 0, 4, 533, 0, 0, 532, 5, 47, 214, 579, 15318, 4, 0, 5383, 0, 38437, 1522, 0, 0, 588453, 1434, 1024, 8589, 1243, 200, 0, 0, 0, 1198, 0, 0, 1391, 122970, 255, 0, 2308, 7, 175817, 195185, 422, 0, 0, 119436, 2, 0, 35778, 59, 346, 1, 0, 175, 51, 54, 159656, 0, 208, 0, 0, 0, 0, 0, 302, 0, 19, 336, 201, 282, 231, 137, 187861, 405, 171562, 212, 345, 292, 0, 67, 18, 0, 0, 304, 0, 19, 135, 0, 0, 0, 53307, 0, 54896, 65818, 157587, 28435368, 0, 157587, 200160, 54, 1206, 23781585, 29154517, 52937308, 16859136, 0, 9547422, 0, 7716864, 1225042, 884736, 5822508, 82509240, 27671, 2617037149, 2619716689, 82364468, 1097, 0, 35348464, 1621, 0, 4440, 1, 460617, 475035, 2, 18, 2, 0, 13, 4270, 0, 136, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 118, 1898, 728928, 245817, 147, 1272, 425, 65549, 683665, 67687, 0, 2585, 143513, 30368, 12974, 3695, 1875, 1499, 655, 417, 139, 8, 9, 25, 8, 0, 0, 0, 0, 0, 1545, 908, 247, 925, 680, 2096, 28678, 56694, 29813, 28547, 17426, 8039, 2991, 1552, 1310, 983, 553, 394, 0, 0, 0, 0, 1, 0, 0, 0, 0, 28, 0, 0, 95, 0, 0, 0, 0, 0, 0, 3, 0, 0, 0, 0, 0, 116, 0, 197, 0, 0, 98, 0, 0, 0, 1, 0, 0, 1, 0, 10, 0, 0, 50, 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 328, 118, 0, 0, 0, 0, 1, 1, 0, 23, 0, 21850297, 0, 0, 2, 93, 0, 0, 2, 0
08:04:16 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: session_stats_alert
08:04:16 [DEBUG   ][deluge.core.rpcserver         :547 ] intevents: {9: ['ConfigValueChangedEvent', 'PluginEnabledEvent', 'PluginDisabledEvent', 'TorrentStateChangedEvent', 'TorrentRemovedEvent', 'TorrentAddedEvent']}
08:04:16 [DEBUG   ][deluge.core.rpcserver         :547 ] intevents: {9: ['ConfigValueChangedEvent', 'PluginEnabledEvent', 'PluginDisabledEvent', 'TorrentStateChangedEvent', 'TorrentRemovedEvent', 'TorrentAddedEvent']}
08:04:16 [DEBUG   ][deluge.core.rpcserver         :551 ] Emit Event: TorrentStateChangedEvent ['c4769d7000244e4cae9c054a83e38f168bf4f69f', 'Seeding']
08:04:16 [DEBUG   ][deluge.core.torrent           :678 ] State from lt was: seeding | Session is paused: False
Torrent state set from "Downloading" to "Seeding" (c4769d7000244e4cae9c054a83e38f168bf4f69f)
08:04:16 [DEBUG   ][deluge.core.torrentmanager    :1280] Finished c4769d7000244e4cae9c054a83e38f168bf4f69f
08:04:16 [DEBUG   ][deluge.core.torrentmanager    :1281] Torrent settings: is_finished: False, total_download: 867360982, move_completed: True, move_path: /complete/_test
08:04:16 [DEBUG   ][deluge.core.torrent           :678 ] State from lt was: seeding | Session is paused: False
Torrent state set from "Seeding" to "Seeding" (c4769d7000244e4cae9c054a83e38f168bf4f69f)
08:04:16 [DEBUG   ][deluge.core.rpcserver         :547 ] intevents: {9: ['ConfigValueChangedEvent', 'PluginEnabledEvent', 'PluginDisabledEvent', 'TorrentStateChangedEvent', 'TorrentRemovedEvent', 'TorrentAddedEvent']}
08:04:16 [DEBUG   ][deluge.core.rpcserver         :551 ] Emit Event: TorrentStateChangedEvent ['c4769d7000244e4cae9c054a83e38f168bf4f69f', 'Moving']
08:04:16 [DEBUG   ][deluge.core.torrent           :678 ] State from lt was: seeding | Session is paused: False
Torrent state set from "Seeding" to "Moving" (c4769d7000244e4cae9c054a83e38f168bf4f69f)
08:04:16 [DEBUG   ][deluge.core.torrent           :1330] Requesting save_resume_data for torrent: c4769d7000244e4cae9c054a83e38f168bf4f69f
08:04:16 [DEBUG   ][deluge.core.torrent           :678 ] State from lt was: seeding | Session is paused: False
Torrent state set from "Moving" to "Moving" (c4769d7000244e4cae9c054a83e38f168bf4f69f)
08:04:16 [DEBUG   ][deluge.core.alertmanager      :108 ] Alerts queued: 3
08:04:16 [DEBUG   ][deluge.core.alertmanager      :120 ] save_resume_data_alert: archlinux-2022.09.03-x86_64.iso resume data generated
08:04:16 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: save_resume_data_alert
08:04:16 [DEBUG   ][deluge.core.alertmanager      :120 ] cache_flushed_alert: archlinux-2022.09.03-x86_64.iso
08:04:16 [DEBUG   ][deluge.core.alertmanager      :120 ] storage_moved_failed_alert: archlinux-2022.09.03-x86_64.iso storage move failed. file_seek (/downloads/_test/archlinux-2022.09.03-x86_64.iso): Not supported
08:04:16 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: storage_moved_failed_alert
08:04:16 [WARNING ][deluge.core.torrentmanager    :1433] on_alert_storage_moved_failed: archlinux-2022.09.03-x86_64.iso storage move failed. file_seek (/downloads/_test/archlinux-2022.09.03-x86_64.iso): Not supported
08:04:16 [DEBUG   ][deluge.core.torrentmanager    :1131] Creating the temporary file: /config/state/torrents.fastresume.tmp
08:04:16 [DEBUG   ][deluge.core.rpcserver         :547 ] intevents: {9: ['ConfigValueChangedEvent', 'PluginEnabledEvent', 'PluginDisabledEvent', 'TorrentStateChangedEvent', 'TorrentRemovedEvent', 'TorrentAddedEvent']}
08:04:16 [DEBUG   ][deluge.core.rpcserver         :551 ] Emit Event: TorrentStateChangedEvent ['c4769d7000244e4cae9c054a83e38f168bf4f69f', 'Error']
08:04:16 [DEBUG   ][deluge.core.torrent           :678 ] State from lt was: seeding | Session is paused: False
Torrent state set from "Moving" to "Error" (c4769d7000244e4cae9c054a83e38f168bf4f69f)
08:04:16 [DEBUG   ][deluge.core.torrent           :687 ] Torrent Error state message: Failed to move download folder: Not supported
08:04:16 [DEBUG   ][deluge.core.rpcserver         :547 ] intevents: {9: ['ConfigValueChangedEvent', 'PluginEnabledEvent', 'PluginDisabledEvent', 'TorrentStateChangedEvent', 'TorrentRemovedEvent', 'TorrentAddedEvent']}
08:04:16 [DEBUG   ][deluge.core.torrentmanager    :1141] Creating backup of torrents.fastresume at: /config/state/torrents.fastresume.bak
08:04:16 [DEBUG   ][deluge.core.torrentmanager    :1151] Saving torrents.fastresume to: /config/state/torrents.fastresume
08:04:17 [DEBUG   ][deluge.core.alertmanager      :108 ] Alerts queued: 2
08:04:17 [DEBUG   ][deluge.core.alertmanager      :120 ] torrent_paused_alert: archlinux-2022.09.03-x86_64.iso paused
08:04:17 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: torrent_paused_alert
08:04:17 [DEBUG   ][deluge.core.alertmanager      :120 ] session_stats_alert: session stats (291 values): 1, 1653, 33, 3, 77, 0, 0, 0, 0, 6, 0, 0, 0, 0, 0, 54, 0, 0, 0, 0, 0, 4, 533, 0, 0, 532, 5, 47, 214, 579, 15318, 4, 0, 5383, 0, 38437, 1522, 0, 0, 588453, 1434, 1024, 8589, 1243, 202, 0, 0, 0, 1198, 0, 0, 1391, 123870, 255, 0, 2311, 7, 175826, 195185, 423, 0, 0, 119619, 2, 0, 35781, 61, 346, 1, 0, 180, 51, 54, 159657, 0, 208, 0, 0, 0, 0, 0, 302, 0, 19, 336, 201, 282, 231, 137, 187861, 405, 171562, 212, 345, 292, 0, 67, 18, 0, 0, 304, 0, 19, 135, 0, 0, 0, 53307, 0, 54896, 65818, 157587, 28435368, 0, 157587, 200160, 54, 1206, 23781585, 29154517, 52937308, 16859136, 0, 9547422, 16384, 7716864, 1225042, 884736, 5822508, 82509480, 27671, 2617041234, 2619720829, 82364708, 1097, 0, 35364848, 1621, 0, 4440, 1, 460617, 475035, 2, 18, 2, 0, 13, 4270, 0, 136, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 118, 1898, 729409, 245868, 147, 1272, 425, 65550, 683971, 67687, 0, 2585, 143513, 30368, 12974, 3695, 1875, 1499, 655, 417, 139, 8, 9, 25, 8, 0, 0, 0, 0, 0, 1547, 908, 248, 925, 680, 2096, 28678, 56697, 29813, 28547, 17426, 8039, 2991, 1552, 1310, 983, 553, 394, 0, 1, 0, 0, 0, 0, 0, 0, 0, 22, 0, 0, 2, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 22, 0, 196, 0, 0, 21, 0, 0, 0, 0, 0, 0, 0, 0, 10, 0, 0, 50, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 328, 118, 0, 0, 0, 0, 1, 1, 0, 0, 0, 0, 0, 0, 0, 95, 0, 0, 2, 0
08:04:17 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: session_stats_alert
08:04:17 [DEBUG   ][deluge.core.torrent           :678 ] State from lt was: seeding | Session is paused: False
Torrent state set from "Error" to "Error" (c4769d7000244e4cae9c054a83e38f168bf4f69f)
08:04:17 [DEBUG   ][deluge.core.torrent           :687 ] Torrent Error state message: Failed to move download folder: Not supported
08:04:17 [DEBUG   ][deluge.core.torrent           :1330] Requesting save_resume_data for torrent: c4769d7000244e4cae9c054a83e38f168bf4f69f
08:04:17 [DEBUG   ][deluge.core.torrentmanager    :1131] Creating the temporary file: /config/state/torrents.fastresume.tmp
08:04:17 [DEBUG   ][deluge.core.torrentmanager    :1141] Creating backup of torrents.fastresume at: /config/state/torrents.fastresume.bak
08:04:17 [DEBUG   ][deluge.core.torrentmanager    :1151] Saving torrents.fastresume to: /config/state/torrents.fastresume
08:04:17 [DEBUG   ][deluge.core.alertmanager      :108 ] Alerts queued: 1

The backing NAS is TrueNAS which is based upon FreeBSD.

ITestInProd avatar Sep 15 '22 13:09 ITestInProd

Thanks for testing! this means it's the SEEK_DATA and SEEK_HOLE that isn't supported. stay tuned for an updated patch

arvidn avatar Sep 15 '22 14:09 arvidn

I've updated the patch: https://github.com/arvidn/libtorrent/pull/7077

arvidn avatar Sep 15 '22 15:09 arvidn

So far so good with that patch.

ITestInProd avatar Sep 15 '22 23:09 ITestInProd

Updated to latest libtorrent from git, but problem still exists:

(W) 2022-09-19T00:58:04 - Failed to move torrent. Torrent: "Blind Melon". Source: "/mnt/HRAN12TB12/Хранитель/Alternative & Nu-metal (lossless)". Destination: "/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)". Reason: "Blind Melon storage move failed. file_seek (/mnt/HRAN12TB12/Хранитель/Alternative & Nu-metal (lossless)/Blind Melon/Blind Melon - For My Friends 2008 [FLAC]/Covers/CD.jpg): Нет такого устройства или адреса" (N) 2022-09-19T00:58:04 - Start moving torrent. Torrent: "VA - The Family Values Tour 2001 (2002)". Destination: "/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)" (W) 2022-09-19T00:58:05 - Failed to move torrent. Torrent: "VA - The Family Values Tour 2001 (2002)". Source: "/mnt/HRAN12TB12/Хранитель/Alternative & Nu-metal (lossless)". Destination: "/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)". Reason: "VA - The Family Values Tour 2001 (2002) storage move failed. file_seek (/mnt/HRAN12TB12/Хранитель/Alternative & Nu-metal (lossless)/VA - The Family Values Tour 2001 (2002)/Enhanced/XTRAS/QT3ASSET.X32): Нет такого устройства или адреса" (N) 2022-09-19T00:58:05 - Start moving torrent. Torrent: "Elliott Smith". Destination: "/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)" (W) 2022-09-19T00:58:08 - Failed to move torrent. Torrent: "Elliott Smith". Source: "/mnt/HRAN12TB12/Хранитель/Alternative & Nu-metal (lossless)". Destination: "/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)". Reason: "Elliott Smith storage move failed. file_seek (/mnt/HRAN12TB12/Хранитель/Alternative & Nu-metal (lossless)/Elliott Smith/Elliott Smith - Figure 8.wav): Нет такого устройства или адреса" (N) 2022-09-19T00:58:08 - Start moving torrent. Torrent: "Daughtry". Destination: "/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)" (W) 2022-09-19T00:58:11 - Failed to move torrent. Torrent: "Daughtry". Source: "/mnt/HRAN12TB12/Хранитель/Alternative & Nu-metal (lossless)". Destination: "/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)". Reason: "Daughtry storage move failed. file_seek (/mnt/HRAN12TB12/Хранитель/Alternative & Nu-metal (lossless)/Daughtry/Daughtry - Daughtry.flac): Нет такого устройства или адреса" (N) 2022-09-19T00:58:11 - Start moving torrent. Torrent: "Сага о Форсайтах (Е.Терновский, 2013)". Destination: "/mnt/HRAN2X6TB3/Аудиокниги (AAC, ALAC)" (W) 2022-09-19T00:58:12 - Failed to move torrent. Torrent: "Сага о Форсайтах (Е.Терновский, 2013)". Source: "/mnt/HRAN12TB12/Хранитель/Аудиокниги (AAC, ALAC)". Destination: "/mnt/HRAN2X6TB3/Аудиокниги (AAC, ALAC)". Reason: "Сага о Форсайтах (Е.Терновский, 2013) storage move failed. file_seek (/mnt/HRAN12TB12/Хранитель/Аудиокниги (AAC, ALAC)/Сага о Форсайтах (Е.Терновский, 2013)/Книга 2. В петле.m4b): Нет такого устройства или адреса" (N) 2022-09-19T00:58:12 - Start moving torrent. Torrent: "Therapy If it kills me (single)". Destination: "/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)" (W) 2022-09-19T00:58:16 - Failed to move torrent. Torrent: "Therapy If it kills me (single)". Source: "/mnt/HRAN12TB12/Хранитель/Alternative & Nu-metal (lossless)". Destination: "/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)". Reason: "Therapy If it kills me (single) storage move failed. file_seek (/mnt/HRAN12TB12/Хранитель/Alternative & Nu-metal (lossless)/Therapy If it kills me (single)/IfItKillsMeCover.tif): Нет такого устройства или адреса" (N) 2022-09-19T00:58:16 - Start moving torrent. Torrent: "Therapy Trigger inside (single)". Destination: "/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)" (W) 2022-09-19T00:58:17 - Failed to move torrent. Torrent: "Therapy Trigger inside (single)". Source: "/mnt/HRAN12TB12/Хранитель/Alternative & Nu-metal (lossless)". Destination: "/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)". Reason: "Therapy Trigger inside (single) storage move failed. file_seek (/mnt/HRAN12TB12/Хранитель/Alternative & Nu-metal (lossless)/Therapy Trigger inside (single)/TriggerInsideCover.tif): Нет такого устройства или адреса"

May be someone can test couple of this torrents? https://rutracker.org/forum/viewtopic.php?t=2827847 https://rutracker.org/forum/viewtopic.php?t=4323335 https://rutracker.org/forum/viewtopic.php?t=1207219

I've noticed - this error appears only on small files that is inside some folders. Single files or big files always good.

Aleksman4o avatar Sep 18 '22 22:09 Aleksman4o

@Aleksman4o can you share which filesystem you use?

it's odd that lseek() would return ENODEV. The linux man page does not document that as a possible failure. I could add that to the list of error codes to cause fall-back on plain file copy.

arvidn avatar Sep 18 '22 22:09 arvidn

it's ZFS

Aleksman4o avatar Sep 18 '22 22:09 Aleksman4o

I could add that to the list of error codes to cause fall-back on plain file copy.

Waiting this very much :)

Aleksman4o avatar Sep 21 '22 15:09 Aleksman4o

could you test this? https://github.com/arvidn/libtorrent/pull/7109

arvidn avatar Sep 25 '22 15:09 arvidn

Not working. 2 of 4 problem torrents with error: (W) 2022-09-25T20:18:24 - Не удалось переместить торрент. Торрент: «Daughtry». Источник: «/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)». Назначение: «/mnt/ssd_cache/quick_download». Причина: «Daughtry storage move failed. file_seek (/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)/Daughtry/Daughtry - Daughtry.flac): Нет такого устройства или адреса» (W) 2022-09-25T20:21:53 - Не удалось переместить торрент. Торрент: «Blind Melon». Источник: «/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)». Назначение: «/mnt/ssd_cache/quick_download». Причина: «Blind Melon storage move failed. file_seek (/mnt/HRAN2X6TB3/Alternative & Nu-metal (lossless)/Blind Melon/Blind Melon - For My Friends 2008 [FLAC]/Covers/CD.jpg): Нет такого устройства или адреса»

Aleksman4o avatar Sep 25 '22 17:09 Aleksman4o

I'm relying on google translate, suggesting "No such device or address" is ENODEV. Is there any chance you can tell me which errno value that message corresponds to on your system?

arvidn avatar Sep 25 '22 18:09 arvidn

I see, It's ENXIO

arvidn avatar Sep 25 '22 18:09 arvidn

I've updated the PR

arvidn avatar Sep 25 '22 18:09 arvidn

Yeah, it's moving now! Thank you very much! :)

Aleksman4o avatar Sep 25 '22 19:09 Aleksman4o

thanks for reporting and testing!

arvidn avatar Sep 25 '22 20:09 arvidn