Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

No progress indicated for openstack image uploads #154

Open
cmouse opened this issue Mar 18, 2021 · 4 comments
Open

No progress indicated for openstack image uploads #154

cmouse opened this issue Mar 18, 2021 · 4 comments

Comments

@cmouse
Copy link

cmouse commented Mar 18, 2021

Version 3e27660

When trying to monitor openstack image upload, only 0/s is shown.

progress -mp 3884149
[3884149] python3.8 /home/cmouse/Downloads/flatcar_production_openstack_image.raw
        0.0% (0 / 8.5 GiB) 0/s
strace -p 3884149
write(5, "\27\3\3 \30\230\200z\267\325h\v\206\333\223\207;\366\336\343p\222\333\352\270W\343f\322\3745\263"..., 8221) = 8221
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 8192
write(5, "\27\3\3 \30\230\200z\267\325h\v\207\347\246\353\0\211\251\31\331\346\312\227\271*\273\303\351-\332\313"..., 8221) = 8221
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 8192
write(5, "\27\3\3 \30\230\200z\267\325h\v\210\326~\226 \363s\246\30\376\31\235\366s\7\37>\343\326b"..., 8221) = 8221
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 8192
write(5, "\27\3\3 \30\230\200z\267\325h\v\211\3405\312\272\250\367\373\307\5\26\214\355\272\352i\247\30\250\332"..., 8221) = 8221
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 8192
write(5, "\27\3\3 \30\230\200z\267\325h\v\212}\261h\325\374o\324\335\367K\35\352_\360]\257\3537\f"..., 8221) = 8221
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 8192
write(5, "\27\3\3 \30\230\200z\267\325h\v\213[\246\213V\217\341\211.\356q\370\356\343)6\373\352B\200"..., 8221) = 8221
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 8192
write(5, "\27\3\3 \30\230\200z\267\325h\v\214\250DJ\355:\3634s1\342F<\207\3338\230\250\332\363"..., 8221) = 8221
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 8192
write(5, "\27\3\3 \30\230\200z\267\325h\v\2156\1I\2320\232E5\313\217\303\t\226\260k\5\344\33'"..., 8221) = 8221
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 8192
write(5, "\27\3\3 \30\230\200z\267\325h\v\216\340\342/c\300K\373eC\206\33\357\304\225\326\242I\347\325"..., 8221) = 8221
read(4, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 8192
::::::::::::::
/proc/3884149/fdinfo/0
::::::::::::::
pos:	0
flags:	02002
mnt_id:	28
::::::::::::::
/proc/3884149/fdinfo/1
::::::::::::::
pos:	0
flags:	02002
mnt_id:	28
::::::::::::::
/proc/3884149/fdinfo/2
::::::::::::::
pos:	0
flags:	02002
mnt_id:	28
::::::::::::::
/proc/3884149/fdinfo/3
::::::::::::::
pos:	0
flags:	02100000
mnt_id:	30
::::::::::::::
/proc/3884149/fdinfo/4
::::::::::::::
pos:	3793813504
flags:	02100000
mnt_id:	30
::::::::::::::
/proc/3884149/fdinfo/5
::::::::::::::
pos:	0
flags:	02000002
mnt_id:	10
### after few seconds
::::::::::::::
/proc/3884149/fdinfo/0
::::::::::::::
pos:	0
flags:	02002
mnt_id:	28
::::::::::::::
/proc/3884149/fdinfo/1
::::::::::::::
pos:	0
flags:	02002
mnt_id:	28
::::::::::::::
/proc/3884149/fdinfo/2
::::::::::::::
pos:	0
flags:	02002
mnt_id:	28
::::::::::::::
/proc/3884149/fdinfo/3
::::::::::::::
pos:	0
flags:	02100000
mnt_id:	30
::::::::::::::
/proc/3884149/fdinfo/4
::::::::::::::
pos:	3860611072
flags:	02100000
mnt_id:	30
::::::::::::::
/proc/3884149/fdinfo/5
::::::::::::::
pos:	0
flags:	02000002
mnt_id:	10
@cmouse
Copy link
Author

cmouse commented Mar 18, 2021

It would seem the problem is that the fd is seeked to 0, and then back constantly

fd->pos = 0
fd->pos = 4565688320
fd->pos = 0

@cmouse
Copy link
Author

cmouse commented Mar 18, 2021

After some debugging it seems that the real problem is that the same file is opened twice:

$ ls -l /proc/3884149/fd/
total 0
lrwx------ 1 cmouse cmouse 64 maalis 18 12:21 0 -> /dev/pts/2
lrwx------ 1 cmouse cmouse 64 maalis 18 12:21 1 -> /dev/pts/2
lrwx------ 1 cmouse cmouse 64 maalis 18 12:21 2 -> /dev/pts/2
lr-x------ 1 cmouse cmouse 64 maalis 18 12:21 3 -> /home/cmouse/Downloads/flatcar_production_openstack_image.raw
lr-x------ 1 cmouse cmouse 64 maalis 18 12:21 4 -> /home/cmouse/Downloads/flatcar_production_openstack_image.raw
lrwx------ 1 cmouse cmouse 64 maalis 18 12:21 5 -> 'socket:[1314379516]'

And it's trying to measure progress from 3 and 4, and ends up looking only on 3, which isn't progressing. When I manually changed it to always look at 4, it shows progress.

@Xfennec
Copy link
Owner

Xfennec commented Apr 26, 2021

This is a very specific situation, but we could imagine a very generic fix ("if the file is opened multiple times, look for the biggest seek").

@cmouse
Copy link
Author

cmouse commented Apr 26, 2021

I think that fd 3 actually was always 0. So you could maybe just ignore it as it's not really progressing anywhere?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants