Cannot upload videos on youtube since september 9th, 2017 nightly because of bug 1397627 ?

VERIFIED FIXED in Firefox 57

Status

()

Core
DOM: File
VERIFIED FIXED
a month ago
a month ago

People

(Reporter: Frederic Bezies, Assigned: baku)

Tracking

({regression, steps-wanted})

Trunk
mozilla57
regression, steps-wanted
Points:
---

Firefox Tracking Flags

(firefox-esr52 unaffected, firefox55 unaffected, firefox56 unaffected, firefox57 verified)

Details

Attachments

(1 attachment, 3 obsolete attachments)

(Reporter)

Description

a month ago
This is a fresh regression. Steps to reproduce it with a nightly from september 9th 2017 and after:

1) Open your youtube account
2) Click on upload arrow
3) Select a video to import
4) Wait until publish button can be clicked
5) Wait and see that progress bar is stuck at 0%


Using mozregression with a clean profile, I got this regression window:

Last good mozilla-inbound build: https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=dce4d3db04bf1eb303a4e05f4d3cf9f1baf0f110&tochange=6933c6396bda51a32059f7bbd24349ff9cda2eaf

First broken mozilla-inbound build: https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=560c9ee4d5843aca014f83af958c9b8382084cf5&tochange=6933c6396bda51a32059f7bbd24349ff9cda2eaf
 
So, it could be one of these changesets :

* 6933c6396bda
* c08a59cb75a3
* 85b18b5a5e43
* f77a81b06e43
* b4f8fad33b2f
* dce4d3db04bf

Looks like bug 1397627 is the culprit here. Or it could be :)

Comment 1

a month ago
[Tracking Requested - why for this release]:
tracking-firefox57: --- → ?
Flags: needinfo?(amarchesini)
Keywords: regression
(Assignee)

Comment 2

a month ago
I suspect it's a duplicate of bug 1397645.
Youtube creates a blob slice and it reads part of it. With bug 1397627, IPCBlobInputStream is not seekable and we end up using consecutive read() to reach the sliced position. This means that the youtube upload is extremely slow, but at some point, the upload will be executed. Bug 1397645 fixes this performance issue.
Flags: needinfo?(amarchesini)
(Assignee)

Updated

a month ago
Status: NEW → RESOLVED
Last Resolved: a month ago
Resolution: --- → DUPLICATE
Duplicate of bug: 1397645
already tracked in bug 1397645
status-firefox57: affected → ---
tracking-firefox57: ? → ---
(Reporter)

Comment 5

a month ago
Sorry. I still cannot upload a video on Youtube using a nightly based on this commit : https://hg.mozilla.org/mozilla-central/rev/b0e945eed81db8bf076daf64e381c514f70144f0

Do I have to reopen this bug ?
(Assignee)

Comment 6

a month ago
I did some test and I was able to upload a video. Tell me more: what's the size and mime type of the video?
Flags: needinfo?(fredbezies)
Does it matter what OS you're uploading from?  I am worried this may not be a duplicate, so reopening. It will help if we can reproduce the problem.
Status: RESOLVED → REOPENED
status-firefox57: --- → affected
Keywords: steps-wanted
Resolution: DUPLICATE → ---
Frederic, if you have time, can you try uploading the same file with the most recent Firefox Beta build? Thanks. It will help to know if this is a regression from 57 or from 56.
status-firefox56: --- → ?
(Reporter)

Comment 9

a month ago
Pasted this also on bug #1399215

All tests done here with addons disabled.

Tested with two files :

* a m4v file known as ISO Media, MP4 v2 [ISO 14496-14] - 217.3 Mb
* a mp4 file known as ISO Media, MP4 Base Media v1 [IS0 14496-12:2003] - 29.7 Mb

I) Nightly reports :

Using nightly based on this commit :

https://hg.mozilla.org/mozilla-central/rev/a73cc4e08bf5a005722c95b43f84ab0c8ff2bc7c

Both uploads are broken. Size doesn't seems to matter here.

II) Firefox 56.0 beta : 

With latest beta which seems to be 56.0b11. For both files, upload is started in less than a second after import progress page is displayed...

So there is a bug in nightly code.

My OS : Archlinux.
Flags: needinfo?(fredbezies)
(Assignee)

Comment 10

a month ago
> So there is a bug in nightly code.

I'm kind of able to reproduce it. The behavior is really strange. I see the progress-bar blocked to 0% for quite a while and then it jumps to 95% and the upload ends correctly.

Working on it.
Assignee: nobody → amarchesini
(Assignee)

Comment 11

a month ago
Created attachment 8907553 [details] [diff] [review]
deadlock.patch
Attachment #8907553 - Flags: review?(bugs)
Comment on attachment 8907553 [details] [diff] [review]
deadlock.patch

(new patch coming)
Attachment #8907553 - Flags: review?(bugs)
(Assignee)

Comment 13

a month ago
Created attachment 8907576 [details] [diff] [review]
deadlock.patch
Attachment #8907553 - Attachment is obsolete: true
Attachment #8907576 - Flags: review?(bugs)
(Assignee)

Updated

a month ago
Attachment #8907576 - Flags: review?(bugs)
(Assignee)

Comment 14

a month ago
Created attachment 8907582 [details] [diff] [review]
deadlock.patch
Attachment #8907576 - Attachment is obsolete: true
Attachment #8907582 - Flags: review?(bugs)
(Assignee)

Comment 15

a month ago
Created attachment 8907584 [details] [diff] [review]
deadlock.patch
Attachment #8907582 - Attachment is obsolete: true
Attachment #8907582 - Flags: review?(bugs)
Attachment #8907584 - Flags: review?(bugs)
Comment on attachment 8907584 [details] [diff] [review]
deadlock.patch

I think IPCBlobInputStream::AsyncWait should MOZ_ASSERT before NS_ERROR_FAILURE to catch issues in debug builds.
Attachment #8907584 - Flags: review?(bugs) → review+

Comment 17

a month ago
Pushed by amarchesini@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/0140b9418003
IPCBlobInputStream should call OnInputStreamReady() on the current thread if ::AsyncWait() is called without passing nsIEventTarget, r=smaug
(Assignee)

Updated

a month ago
Duplicate of this bug: 1399215
per comment 9
status-firefox56: ? → unaffected
Backed out for asserting at dom/file/ipc/IPCBlobInputStream.cpp:555:

https://hg.mozilla.org/integration/mozilla-inbound/rev/68008e66e9df81581c20f6d036f86eeaeea2eee4

Push which ran failing tests: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=b382ec54d164fde891d5f520fd15654d1d521ba9&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable
Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=130664893&repo=mozilla-inbound

07:26:11     INFO -  4955 INFO None4956 INFO TEST-START | dom/indexedDB/test/test_wasm_getAll.html
07:26:11     INFO -  GECKO(1863) | [Child 1864, Main Thread] WARNING: stylo: ServoStyleSets cannot respond to document state changes yet (only matters for chrome documents). See bug 1290285.: file /builds/worker/workspace/build/src/layout/base/PresShell.cpp, line 4297
07:26:11     INFO -  GECKO(1863) | ++DOMWINDOW == 33 (0x11f20e000) [pid = 1864] [serial = 357] [outer = 0x11f468800]
07:26:11     INFO -  GECKO(1863) | [Child 1864, Main Thread] WARNING: stylo: Web Components not supported yet: file /builds/worker/workspace/build/src/dom/base/nsDocument.cpp, line 6413
07:26:11     INFO -  GECKO(1863) | [Child 1864, Main Thread] WARNING: stylo: Web Components not supported yet: file /builds/worker/workspace/build/src/dom/base/nsDocument.cpp, line 6413
07:26:11     INFO -  GECKO(1863) | [Child 1864, Main Thread] WARNING: Unable to find interface object on global: file /builds/worker/workspace/build/src/dom/base/nsDOMClassInfo.cpp, line 1773
07:26:11     INFO -  GECKO(1863) | [Child 1864, Main Thread] WARNING: stylo: ServoStyleSets cannot respond to document state changes yet (only matters for chrome documents). See bug 1290285.: file /builds/worker/workspace/build/src/layout/base/PresShell.cpp, line 4297
07:26:12     INFO -  GECKO(1863) | [Child 1864, StreamTrans #7] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/indexedDB/ActorsChild.cpp, line 885
07:26:12     INFO -  GECKO(1863) | Assertion failure: !!aCallback != !!aEventTarget, at /builds/worker/workspace/build/src/dom/file/ipc/IPCBlobInputStream.cpp:555
07:26:12     INFO -  GECKO(1863) | [Child 1864, StreamTrans #8] WARNING: 'NS_FAILED(rv)', file /builds/worker/workspace/build/src/dom/indexedDB/ActorsChild.cpp, line 885
07:26:12     INFO -  GECKO(1863) | Assertion failure: !!aCallback != !!aEventTarget, at /builds/worker/workspace/build/src/dom/file/ipc/IPCBlobInputStream.cpp:555
07:26:12     INFO -  GECKO(1863) | #01: mozilla::dom::indexedDB::BackgroundRequestChild::PreprocessHelper::WaitForStreamReady(nsIInputStream*) [dom/indexedDB/ActorsChild.cpp:3529]
07:26:12     INFO -  GECKO(1863) | #01: mozilla::dom::indexedDB::BackgroundRequestChild::PreprocessHelper::WaitForStreamReady(nsIInputStream*) [dom/indexedDB/ActorsChild.cpp:3529]
07:26:12     INFO -  GECKO(1863) | #02: mozilla::dom::indexedDB::BackgroundRequestChild::PreprocessHelper::ProcessCurrentStreamPair() [dom/indexedDB/ActorsChild.cpp:3470]
07:26:12     INFO -  GECKO(1863) | #02: mozilla::dom::indexedDB::BackgroundRequestChild::PreprocessHelper::ProcessCurrentStreamPair() [dom/indexedDB/ActorsChild.cpp:3470]
07:26:12     INFO -  GECKO(1863) | #03: mozilla::dom::indexedDB::BackgroundRequestChild::PreprocessHelper::Run() [dom/indexedDB/ActorsChild.cpp:3596]
07:26:12     INFO -  GECKO(1863) | #03: mozilla::dom::indexedDB::BackgroundRequestChild::PreprocessHelper::Run() [dom/indexedDB/ActorsChild.cpp:3596]
07:26:12     INFO -  GECKO(1863) | #04: mozilla::TaskQueue::Runner::Run() [xpcom/threads/TaskQueue.h:175]
07:26:12     INFO -  GECKO(1863) | #04: mozilla::TaskQueue::Runner::Run() [xpcom/threads/TaskQueue.h:175]
07:26:12     INFO -  GECKO(1863) | #05: nsThreadPool::Run() [xpcom/base/nsCOMPtr.h:424]
07:26:12     INFO -  GECKO(1863) | #05: nsThreadPool::Run() [xpcom/base/nsCOMPtr.h:424]
07:26:12     INFO -  GECKO(1863) | #06: non-virtual thunk to nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:154]
07:26:12     INFO -  GECKO(1863) | #06: non-virtual thunk to nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:154]
07:26:12     INFO -  GECKO(1863) | #07: nsThread::ProcessNextEvent(bool, bool*) [mfbt/Maybe.h:224]
07:26:12     INFO -  GECKO(1863) | #07: nsThread::ProcessNextEvent(bool, bool*) [mfbt/Maybe.h:224]
07:26:12     INFO -  GECKO(1863) | #08: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:521]
07:26:12     INFO -  GECKO(1863) | #08: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:521]
07:26:12     INFO -  GECKO(1863) | #09: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:368]
07:26:12     INFO -  GECKO(1863) | #09: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:368]
07:26:12     INFO -  GECKO(1863) | #10: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:599]
07:26:12     INFO -  GECKO(1863) | #10: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:599]
07:26:12     INFO -  GECKO(1863) | #11: nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:429]
07:26:13     INFO -  GECKO(1863) | #12: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:219]
07:26:13     INFO -  GECKO(1863) | #11: nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:429]
07:26:13     INFO -  GECKO(1863) | #13: libsystem_pthread.dylib + 0x405a
07:26:13     INFO -  GECKO(1863) | #12: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:219]
07:26:13     INFO -  GECKO(1863) | #14: libsystem_pthread.dylib + 0x3fd7
07:26:13     INFO -  GECKO(1863) | #13: libsystem_pthread.dylib + 0x405a
07:26:13     INFO -  GECKO(1863) | #14: libsystem_pthread.dylib + 0x3fd7
07:26:13     INFO -  GECKO(1863) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x150081,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
07:26:13     INFO -  GECKO(1863) | Assertion failure: mInternalState == InternalState::Completed, at /builds/worker/workspace/build/src/dom/indexedDB/ActorsParent.cpp:23530
07:26:13     INFO -  GECKO(1863) | ++DOCSHELL 0x114ae3000 == 4 [pid = 1863] [id = {2d391360-dee7-ce4f-9bb6-b082b9b3692e}]
07:26:13     INFO -  GECKO(1863) | ++DOMWINDOW == 7 (0x114ae3800) [pid = 1863] [serial = 9] [outer = 0x0]
07:26:13     INFO -  GECKO(1863) | #01: <name omitted> [memory/mozalloc/mozalloc.h:230]
07:26:13     INFO -  GECKO(1863) | #02: mozilla::Runnable::Release() [xpcom/threads/nsThreadUtils.cpp:44]
07:26:13     INFO -  GECKO(1863) | #03: mozilla::dom::indexedDB::(anonymous namespace)::DatabaseOperationBase::Release() [dom/indexedDB/ActorsParent.cpp:20531]
07:26:13     INFO -  GECKO(1863) | #04: non-virtual thunk to mozilla::dom::indexedDB::(anonymous namespace)::NormalTransaction::DeallocPBackgroundIDBRequestParent(mozilla::dom::indexedDB::PBackgroundIDBRequestParent*) [dom/indexedDB/ActorsParent.cpp:7191]
07:26:13     INFO -  GECKO(1863) | #05: mozilla::dom::indexedDB::PBackgroundIDBTransactionParent::DeallocSubtree() [s3:gecko-generated-sources:b9725e58b8f1f47d9d970ef91bbd3e4d324668a72ea885387dd27d694f8a45de649db2ac35db1e510b4b4fc9ab4a9e950133f416435c13b80d4b97bdf3abf3af/ipc/ipdl/PBackgroundIDBTransactionParent.cpp::418]
07:26:13     INFO -  GECKO(1863) | #06: mozilla::dom::indexedDB::PBackgroundIDBDatabaseParent::DeallocSubtree() [s3:gecko-generated-sources:7b99214916bc441e6ac01063ece6303ca59fa77a2795c8bded90f459579b21f7c5598a8d5ee5cc31647753ece1d4f037e195da4cdb1551891537121f2396b8e0/ipc/ipdl/PBackgroundIDBDatabaseParent.cpp::750]
07:26:13     INFO -  GECKO(1863) | #07: mozilla::dom::indexedDB::PBackgroundIDBFactoryParent::DeallocSubtree() [s3:gecko-generated-sources:37ff90e4296b141264b2ae343a1eb301beb9fbbe7cc0a4ca9ba36c45b6c8dcd74632fd193432602e090e5839927226a9527a8ad5980798305977a2d9c2bf44a9/ipc/ipdl/PBackgroundIDBFactoryParent.cpp::352]
07:26:13     INFO -  GECKO(1863) | #08: mozilla::ipc::PBackgroundParent::DeallocSubtree() [s3:gecko-generated-sources:ac7a48ecceccca97c2f006fc5647c02fd67d3fd1bdfd195fe0b7a04ddb3e12154acca949051dbe853a043d543aa25480a89174127a05f7a6e6f22fc842ddbc17/ipc/ipdl/PBackgroundParent.cpp::2733]
07:26:13     INFO -  GECKO(1863) | #09: mozilla::ipc::PBackgroundParent::OnChannelError() [s3:gecko-generated-sources:ac7a48ecceccca97c2f006fc5647c02fd67d3fd1bdfd195fe0b7a04ddb3e12154acca949051dbe853a043d543aa25480a89174127a05f7a6e6f22fc842ddbc17/ipc/ipdl/PBackgroundParent.cpp::2397]
07:26:13     INFO -  GECKO(1863) | ++DOMWINDOW == 8 (0x116d08000) [pid = 1863] [serial = 10] [outer = 0x114ae3800]
07:26:13     INFO -  GECKO(1863) | #10: mozilla::detail::RunnableMethodImpl<mozilla::ipc::MessageChannel*, void (mozilla::ipc::MessageChannel::*)(), false, (mozilla::RunnableKind)1>::Run() [xpcom/threads/nsThreadUtils.h:1142]
07:26:13     INFO -  GECKO(1863) | #11: nsThread::ProcessNextEvent(bool, bool*) [mfbt/Maybe.h:224]
07:26:13     INFO -  GECKO(1863) | #12: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:521]
07:26:13     INFO -  GECKO(1863) | #13: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:368]
07:26:13     INFO -  GECKO(1863) | #14: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:599]
07:26:13     INFO -  GECKO(1863) | #15: nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:429]
07:26:13     INFO -  GECKO(1863) | #16: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:219]
07:26:13     INFO -  GECKO(1863) | #17: libsystem_pthread.dylib + 0x405a
07:26:13     INFO -  GECKO(1863) | #18: libsystem_pthread.dylib + 0x3fd7
07:26:13     INFO -  TEST-INFO | Main app process: exit 1
07:26:13     INFO -  Buffered messages logged at 07:26:11
07:26:13     INFO -  4957 INFO Running 'test_wasm_getAll.js'
Flags: needinfo?(amarchesini)
Please also take a look at this crash: https://treeherder.mozilla.org/logviewer.html#?job_id=130678312&repo=mozilla-inbound
Duplicate of this bug: 1399351

Comment 23

a month ago
Pushed by amarchesini@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/6777be860609
IPCBlobInputStream should call OnInputStreamReady() on the current thread if ::AsyncWait() is called without passing nsIEventTarget, r=smaug
Blocks: 1397627
https://hg.mozilla.org/mozilla-central/rev/6777be860609
Status: REOPENED → RESOLVED
Last Resolved: a month agoa month ago
status-firefox57: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla57
(Reporter)

Comment 25

a month ago
You can add verify. I can upload a video on Youtube flawlessly. A good bug is a fixed bug :D
(Assignee)

Comment 26

a month ago
Thank you, Frederic!
Flags: needinfo?(amarchesini)
baku, what was the regression from?  Is it related to the work you want to uplift in bug 1399215? (I want to make sure we don't accidentally ship 56 with this broken).  Thanks.
Flags: needinfo?(amarchesini)
Sorry, I meant, the uplift in bug 1397645.
(Assignee)

Comment 29

a month ago
No. It's a regression generated by bug 1397627. We don't want to uplift this bug nor bug 1397627.
Flags: needinfo?(amarchesini)
status-firefox55: --- → unaffected
status-firefox-esr52: --- → unaffected

Comment 30

a month ago
verify+ per comment 25.
Status: RESOLVED → VERIFIED
status-firefox57: fixed → verified
You need to log in before you can comment on or make changes to this bug.