Race condition in HlsDownloader leading to ConcurrentModificationException & NPE #101

Ilya-Gh · 2021-05-24T13:14:16Z

The Race condition in HlsDownloader leading to ConcurrentModificationException & NPE ocurred after update from v2.6.4 to v2.6.9.

Currently, the HlsDownloader#createDownloadTasks function can be called from 2 places which are run in 2 separate Threads.

On track selection from TrackSelectorImp.apply, which uses AsyncTasks sDefaultExecutor.

playkit-dtg-android/dtglib/src/main/java/com/kaltura/dtg/TrackSelectorImp.java

Line 39 in d92e41e

downloader.apply();
Download services after metadata completes, which uses a ThreadPoolExecutor to invoke HlsDownloader#createDownloadTasks further down the stack via AbrDownloader#apply call.

playkit-dtg-android/dtglib/src/main/java/com/kaltura/dtg/DownloadService.java

Line 395 in d92e41e

newDownload(item);

playkit-dtg-android/dtglib/src/main/java/com/kaltura/dtg/AbrDownloader.java

Line 93 in d92e41e

this.apply();

The race condition appeared after metadata fetching was moved to a dedicated ThreadPoolExecutor from AsyncTasks sDefaultExecutor which was reused reusing the same Thread for both calls.

Steps to reproduce

Start download.
Change track selection at the time when metadata loading finishes.

Expected Results

The download should start.

Actual Results

The following exceptions are thrown from dtg:

Fatal Exception: java.util.ConcurrentModificationException
       at java.util.ArrayList$Itr.next(ArrayList.java:860)
       at com.kaltura.dtg.hls.HlsDownloader.createDownloadTasks(HlsDownloader.java:88)
       at com.kaltura.dtg.AbrDownloader.applyInitialTrackSelection(AbrDownloader.java:122)
       at com.kaltura.dtg.hls.HlsDownloader.applyInitialTrackSelection(HlsDownloader.java:297)
       at com.kaltura.dtg.AbrDownloader.apply(AbrDownloader.java:235)
       at com.kaltura.dtg.TrackSelectorImp.lambda$apply$0(TrackSelectorImp.java:39)
       at com.kaltura.dtg.TrackSelectorImp.lambda$apply$0$TrackSelectorImp(TrackSelectorImp.java)
       at com.kaltura.dtg.-$$Lambda$TrackSelectorImp$nlSaArBap0OhKxA2tNBRIKRHnbY.run(-.java:4)
       at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:289)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
       at java.lang.Thread.run(Thread.java:919)

Fatal Exception: java.lang.NullPointerException: Attempt to read from field 'int i.n.b.b1.a$b.a' on a null object reference
       at com.kaltura.dtg.hls.HlsDownloader.createDownloadTasks(HlsDownloader.java:90)
       at com.kaltura.dtg.AbrDownloader.applyInitialTrackSelection(AbrDownloader.java:122)
       at com.kaltura.dtg.hls.HlsDownloader.applyInitialTrackSelection(HlsDownloader.java:297)
       at com.kaltura.dtg.AbrDownloader.apply(AbrDownloader.java:235)
       at com.kaltura.dtg.TrackSelectorImp.lambda$apply$0(TrackSelectorImp.java:39)
       at com.kaltura.dtg.TrackSelectorImp.lambda$apply$0$TrackSelectorImp(TrackSelectorImp.java)
       at com.kaltura.dtg.-$$Lambda$TrackSelectorImp$nlSaArBap0OhKxA2tNBRIKRHnbY.run(-.java:4)
       at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:289)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
       at java.lang.Thread.run(Thread.java:919)

The text was updated successfully, but these errors were encountered:

kaltura-hooks · 2021-05-24T13:36:56Z

Hi @Ilya-Gh,

Thank for you reporting an issue and helping improve Kaltura!

To get the fastest response time, and help the maintainers review and test your reported issues or suggestions, please ensure that your issue includes the following (please comment with more info if you have not included all this info in your original issue):

Is the issue you're experiencing consistent and across platforms? or does it only happens on certain conditions?
please provide as much details as possible.
Which Kaltura deployment you're using: Kaltura SaaS, or self-hosted?
If self hosted, are you using the RPM or deb install?
Packages installed.
When using RPM, paste the output for:

	# rpm -qa \"kaltura*\"

For deb based systems:

	# dpkg -l \"kaltura-*\"

If running a self hosted ENV - provide the MySQL server version used
If running a self hosted ENV - is this a single all in 1 server or a cluster?
If running a self hosted ENV, while making the problematic request, run:

	# tail -f /opt/kaltura/log/*.log /opt/kaltura/log/batch/*.log | grep -A 1 -B 1 --color \"ERR:\|PHP\|trace\|CRIT\|\[error\]\"

and paste the output.

When relevant, provide any screenshots or screen recordings showing the issue you're experiencing.

For general troubleshooting see:
https://github.com/kaltura/platform-install-packages/blob/Jupiter-10.13.0/doc/kaltura-packages-faq.md#troubleshooting-help

If you only have a general question rather than a bug report, please close this issue and post at:
http://forum.kaltura.org

Thank you in advance,

GouravSna · 2021-05-25T08:41:08Z

Can you please share a sample of your scenario ? Better if you share a fork branch.

Ilya-Gh · 2021-05-25T10:26:03Z

@GouravSna The closer I could get. Ilya-Gh@0756be0

Steps to reproduce:

Start multitrack HLS download
If it does not crash then remove the download and repeat the cycle.

It crashes 20-30% of times for me with the following exception. I guess it can be ConcurrentModificationException sometimes as well as we see in our app (track selection might needed to be adjusted for that)

    Process: com.kaltura.dtg.demo, PID: 28097
    java.lang.NullPointerException: Attempt to read from field 'int com.kaltura.dtg.hls.HlsAsset$Chunk.lineNum' on a null object reference
        at com.kaltura.dtg.hls.HlsDownloader.createDownloadTasks(HlsDownloader.java:90)
        at com.kaltura.dtg.AbrDownloader.applyInitialTrackSelection(AbrDownloader.java:122)
        at com.kaltura.dtg.hls.HlsDownloader.applyInitialTrackSelection(HlsDownloader.java:297)
        at com.kaltura.dtg.AbrDownloader.apply(AbrDownloader.java:235)
        at com.kaltura.dtg.TrackSelectorImp.lambda$apply$0$TrackSelectorImp(TrackSelectorImp.java:39)
        at com.kaltura.dtg.-$$Lambda$TrackSelectorImp$nc8jV5_c5sx4Pk5MMu1__H32Fp8.run(Unknown Source:4)
        at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:289)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
        at java.lang.Thread.run(Thread.java:919)

GouravSna · 2021-06-29T17:54:25Z

Hi @Ilya-Gh ,

As per our architecture , once you call createItem on ContentManager then item state is NEW. Then you call loadMetaData and during this we do fire onTracksAvailable() which helps to do setSelectedTracks (manually or dynamically).

onTracksAvailable() is not meant to be called startDownload because metadata is not ready yet. We do fire onDownloadMetadata which tells the app that now they can call start the download.

loadMetaData was moved to another thread to give the ability to cancel it and it handles db operations etc. Please check our new download sequence for the reference.

Please move your startDownload code to onDownloadMetadata.

Ilya-Gh · 2022-09-21T14:24:29Z

Hey @GouravSna. Thanks for taking a look at the issue, but it's reproducible on our end.

I have double-checked our project. We already call startDownload from onDownloadMetadata callback, as you suggested.

I have remade the sample project by removing startDownload call as it's redundant for this scenario.
Ilya-Gh@e21576d

I have added the code that restarts the download when it finish so it will be easier for you to notice the crash (the reproducibility rate is about 5% for me).

The line that makes the app crash is Ilya-Gh@e21576d#diff-d59630304bf15fb3aa1e3709f4ca60a982485601c69b7eff2d94c94e37cad140R501

The stack trace with the crash:

FATAL EXCEPTION: AsyncTask #2
Process: com.kaltura.dtg.demo, PID: 6983
java.util.ConcurrentModificationException
	at java.util.ArrayList$Itr.next(ArrayList.java:860)
	at com.kaltura.dtg.hls.HlsDownloader.createDownloadTasks(HlsDownloader.java:98)
	at com.kaltura.dtg.AbrDownloader.applyInitialTrackSelection(AbrDownloader.java:122)
	at com.kaltura.dtg.hls.HlsDownloader.applyInitialTrackSelection(HlsDownloader.java:314)
	at com.kaltura.dtg.AbrDownloader.apply(AbrDownloader.java:235)
	at com.kaltura.dtg.TrackSelectorImp.lambda$apply$0$com-kaltura-dtg-TrackSelectorImp(TrackSelectorImp.java:39)
	at com.kaltura.dtg.TrackSelectorImp$$ExternalSyntheticLambda0.run(Unknown Source:4)
	at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:305)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
    at java.lang.Thread.run(Thread.java:920)

Could you please check the first part of the issue, where I described the potential concurrency issue in the code?

Currently, the HlsDownloader#createDownloadTasks function can be called from 2 places which are run in 2 separate Threads.

On track selection from TrackSelectorImp.apply, which uses AsyncTasks sDefaultExecutor.

playkit-dtg-android/dtglib/src/main/java/com/kaltura/dtg/TrackSelectorImp.java

Line 39 in d92e41e

downloader.apply();

Download services after metadata completes, which uses a ThreadPoolExecutor to invoke HlsDownloader#createDownloadTasks further down the stack via AbrDownloader#apply call.

playkit-dtg-android/dtglib/src/main/java/com/kaltura/dtg/DownloadService.java

Line 395 in d92e41e

newDownload(item);

playkit-dtg-android/dtglib/src/main/java/com/kaltura/dtg/AbrDownloader.java

Line 93 in d92e41e

this.apply();

The race condition appeared after metadata fetching was moved to a dedicated ThreadPoolExecutor from AsyncTasks sDefaultExecutor which was reused reusing the same Thread for both calls.

Ilya-Gh · 2022-09-21T14:33:17Z

@GouravSna As this issue is closed. Lets continue the discussion in #115

GouravSna self-assigned this May 24, 2021

GouravSna closed this as completed Jul 19, 2021

Ilya-Gh mentioned this issue Sep 21, 2022

Race condition in HlsDownloader leading to ConcurrentModificationException #115

Closed

GouravSna reopened this Sep 21, 2022

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Race condition in HlsDownloader leading to ConcurrentModificationException & NPE #101

Race condition in HlsDownloader leading to ConcurrentModificationException & NPE #101

Ilya-Gh commented May 24, 2021 •

edited

kaltura-hooks commented May 24, 2021

GouravSna commented May 25, 2021 •

edited

Ilya-Gh commented May 25, 2021 •

edited

GouravSna commented Jun 29, 2021 •

edited

Ilya-Gh commented Sep 21, 2022 •

edited

Ilya-Gh commented Sep 21, 2022

Race condition in HlsDownloader leading to ConcurrentModificationException & NPE #101

Race condition in HlsDownloader leading to ConcurrentModificationException & NPE #101

Comments

Ilya-Gh commented May 24, 2021 • edited

Steps to reproduce

Expected Results

Actual Results

kaltura-hooks commented May 24, 2021

GouravSna commented May 25, 2021 • edited

Ilya-Gh commented May 25, 2021 • edited

GouravSna commented Jun 29, 2021 • edited

Ilya-Gh commented Sep 21, 2022 • edited

Ilya-Gh commented Sep 21, 2022

Ilya-Gh commented May 24, 2021 •

edited

GouravSna commented May 25, 2021 •

edited

Ilya-Gh commented May 25, 2021 •

edited

GouravSna commented Jun 29, 2021 •

edited

Ilya-Gh commented Sep 21, 2022 •

edited