Fixed
Status Update
No update yet.
Comments
ra...@google.com
Can you please describe exactly what method call you're making on ExifInterface? I would expect this to work for exifInterface.setAttribute(TAG_EXPOSURE_TIME, "1/1600") but not exifInterface.setAttribute(TAG_EXPOSURE_TIME, "0.000625").
su...@google.com
I am actually copying EXIF attributes from one image file to another image file. The code looks as follows:
```
val sourceExif = ExifInterface(sourceFilePath)
val destinationExif = ExifInterface(destinationFilePath)
exifTagsList
.associateWith { sourceExif.getAttribute(it) }
.forEach { (tag, value) ->
destinationExif.setAttribute(tag, value)
}
destinationExif.saveAttributes()
```
Where exifTagsList contains the tags I need, e.g. ExifInterface.TAG_EXPOSURE_TIME.
I'm not sure if it's okay to simply read all attributes as String and write them as String, but it worked fine for all tags, except this one.
The attribute value I get for `getAttribute(TAG_EXPOSURE_TIME)` is a String `6.25E-4`. This should be parsed correctly as double value of `0,000625`, which is equal to the actual photo exposure time of `1/1600`.
The problem here is IMO the lack of precision - for higher exposure times like 1/100, 1/50, etc. it works fine. It doesn't for smaller values like 1/1600 or 1/3200.
When you run this code, you will get 1/1666 instead of 1/1600, which I suppose is lack of precision, as 1/1666 = 0,0006:
`exifInterface.setAttribute(TAG_EXPOSURE_TIME, "6.25E-4")`
I tried `exifInterface.setAttribute(TAG_EXPOSURE_TIME, "1/1600")` but it didn't work for me. Probably the interface expects a value that it can parse as double. According to ExifInterface documentation:
> TAG_EXPOSURE_TIME
> Type is double.
```
val sourceExif = ExifInterface(sourceFilePath)
val destinationExif = ExifInterface(destinationFilePath)
exifTagsList
.associateWith { sourceExif.getAttribute(it) }
.forEach { (tag, value) ->
destinationExif.setAttribute(tag, value)
}
destinationExif.saveAttributes()
```
Where exifTagsList contains the tags I need, e.g. ExifInterface.TAG_EXPOSURE_TIME.
I'm not sure if it's okay to simply read all attributes as String and write them as String, but it worked fine for all tags, except this one.
The attribute value I get for `getAttribute(TAG_EXPOSURE_TIME)` is a String `6.25E-4`. This should be parsed correctly as double value of `0,000625`, which is equal to the actual photo exposure time of `1/1600`.
The problem here is IMO the lack of precision - for higher exposure times like 1/100, 1/50, etc. it works fine. It doesn't for smaller values like 1/1600 or 1/3200.
When you run this code, you will get 1/1666 instead of 1/1600, which I suppose is lack of precision, as 1/1666 = 0,0006:
`exifInterface.setAttribute(TAG_EXPOSURE_TIME, "6.25E-4")`
I tried `exifInterface.setAttribute(TAG_EXPOSURE_TIME, "1/1600")` but it didn't work for me. Probably the interface expects a value that it can parse as double. According to ExifInterface documentation:
> TAG_EXPOSURE_TIME
> Type is double.
dr...@gmail.com
Thanks, I think part of the cause of the problem you're seeing is that exifInterface.getAttribute(TAG_EXPOSURE_TIME) is returning "6.25E-4" while setAttribute(TAG_EXPOSURE_TIME, value) is ideally expecting "1/1600".
Turns out there is code to handle the case of passing a decimal string to setAttribute, by converting it to a Rational representation of { int numerator, int denominator }, but it (arbitrarily)
Rational(double value) {
this(/* numerator= */ (long) (value * 10000), /* denominator */ 10000);
}
It looks like this code has been present for a long time, seems it was present in ExifInterface added in 2016
So I think there's an obvious improvement we can make here:
-
Fix the
double->Rationalconversion to support more precision. Ideally we would first try a denominator of1 / value(since this would give an exact result in the case of this bug, and probably most other cases since shutter speeds that are less than 1 are usually1/something), something like:Rational createRationalFromDouble(double value) { double inverse = 1 / value; if (isMathematicalInteger(value)) { return new Rational(1, (long) inverse); } // Not sure what we can do here }For the
elsecase, maybe we could do something clever with continued fractions:https://en.wikipedia.org/wiki/Continued_fraction
It feels like we should also align the format that getAttribute returns with the format setAttribute expects, in order to explicitly support the copying use-case you've described. That would mean changing getAttribute to return "1/1600" in this case. Unfortunately that is a breaking change for any existing code that is doing Double.parseDouble(exifInterface.getAttribute(TAG_EXPOSURE_TIME)), so not feasible. If we were to introduce this it would need to be a separate method.
dr...@gmail.com
Thanks for investigating this problem. It seems like it is indeed the Rational number representation which max decimal precision is up to the 4th decimal place, if I'm not mistaken.
Please also take into account values larger than 1. I think the exposure time might be for example 1,5 second or 15 seconds.
Please also take into account values larger than 1. I think the exposure time might be for example 1,5 second or 15 seconds.
dr...@gmail.com
I also thought that besides fixing this issue, it would be useful to have an API with which one could copy all EXIF data directly from one file to another. This would be useful for use cases like scaling an image file and keeping all its EXIF properties. I think I saw some threads by other developers also missing such feature.
dr...@gmail.com
it would be useful to have an API with which one could copy all EXIF data directly from one file to another
This request is tracked by
su...@google.com
There's another curiosity here: Some 'unsigned rational' tags are returned from getAttribute(String) in the form "x/y", e.g. TAG_FOCAL_LENGTH. I dug a bit into this, and I think the 'automatically convert to floating point' behaviour was originally introduced in the framework version of ExifInterface (which existed before the AndroidX one was forked from it) as part of
Given the constraint of maintaining this lossy format going forward:
ExifInterface already has 'different type' getAttributeXXX(...) 'overloads' like getAttributeInt(...). Given these already exist, we could consider adding add a @Nullable String getAttributeRational(String) that returns the "x/y" format for tags with TYPE = (Unsigned) rational. People would have to know to use it instead of getAttribute(String), but it at least gives 'lossless' access to the actual tag data read from the file - even for rational tags that are converted to lossy decimal/floating-point representations for backwards-compatibility..
ra...@google.com
Project: platform/frameworks/support
Branch: androidx-main
commit e497a91fac8b9826b122ccc1b012c8dd58fc1269
Author: Ian Baker <ibaker@google.com>
Date: Tue Apr 02 14:02:28 2024
Tighten floating point assertions in ExifInterfaceTest
As part of addressing
ExifInterface converts floating point strings to rational
representations. In order to add a test for this (that fails without
the fix) I need to first tighten the precision of the existing floating
point assertions in the test.
Bug: 312680558
Test: ExifInterfaceTest
Change-Id: Id15b4beebfe504a2e8e6a76725ed871fc41921ac
M exifinterface/exifinterface/src/androidTest/java/androidx/exifinterface/media/ExifInterfaceTest.java
M exifinterface/exifinterface/src/androidTest/java/androidx/exifinterface/media/ExpectedAttributes.java
https://android-review.googlesource.com/3022384
Branch: androidx-main
commit e497a91fac8b9826b122ccc1b012c8dd58fc1269
Author: Ian Baker <ibaker@google.com>
Date: Tue Apr 02 14:02:28 2024
Tighten floating point assertions in ExifInterfaceTest
As part of addressing
ExifInterface converts floating point strings to rational
representations. In order to add a test for this (that fails without
the fix) I need to first tighten the precision of the existing floating
point assertions in the test.
Bug: 312680558
Test: ExifInterfaceTest
Change-Id: Id15b4beebfe504a2e8e6a76725ed871fc41921ac
M exifinterface/exifinterface/src/androidTest/java/androidx/exifinterface/media/ExifInterfaceTest.java
M exifinterface/exifinterface/src/androidTest/java/androidx/exifinterface/media/ExpectedAttributes.java
ra...@google.com
Project: platform/frameworks/support
Branch: androidx-main
commit 13cb54333c5e3202da0e2cdb566f0810fd217ae1
Author: Ian Baker <ibaker@google.com>
Date: Tue Apr 09 17:16:37 2024
Accept rationals (x/y) for attrs with legacy handling in ExifInterface
Some attributes declared/documented as type = Rational have special
handling for backwards compatibility that results in their values being
returned as decimals instead. Previous to this change, only decimal
values were accepted too, but we can accept both decimal and rational
forms without breaking backwards compatibility.
See more context about the backwards compat in this internal code review
comment from 2016:
http://ag/c/platform/frameworks/base/+/909922/2..9/api/current.txt#b20093
Bug: 312680558
Test: ExifInterfaceTest
Change-Id: Ie282c1f8a23297f51a31b04c290284124eb870f9
M exifinterface/exifinterface/src/androidTest/java/androidx/exifinterface/media/ExifInterfaceTest.java
M exifinterface/exifinterface/src/main/java/androidx/exifinterface/media/ExifInterface.java
https://android-review.googlesource.com/3037114
Branch: androidx-main
commit 13cb54333c5e3202da0e2cdb566f0810fd217ae1
Author: Ian Baker <ibaker@google.com>
Date: Tue Apr 09 17:16:37 2024
Accept rationals (x/y) for attrs with legacy handling in ExifInterface
Some attributes declared/documented as type = Rational have special
handling for backwards compatibility that results in their values being
returned as decimals instead. Previous to this change, only decimal
values were accepted too, but we can accept both decimal and rational
forms without breaking backwards compatibility.
See more context about the backwards compat in this internal code review
comment from 2016:
Bug: 312680558
Test: ExifInterfaceTest
Change-Id: Ie282c1f8a23297f51a31b04c290284124eb870f9
M exifinterface/exifinterface/src/androidTest/java/androidx/exifinterface/media/ExifInterfaceTest.java
M exifinterface/exifinterface/src/main/java/androidx/exifinterface/media/ExifInterface.java
dr...@gmail.com
Project: platform/frameworks/support
Branch: androidx-main
commit c23003716636d5c161e9b8c5d139ebbde0b7c8b5
Author: Ian Baker <ibaker@google.com>
Date: Wed Apr 10 17:03:20 2024
Split GPS_TIMESTAMP handling from the rest of the backwards compat rational tags
This tag has different special handling to the rest in this set, so it
doesn't really make sense to include it here.
Bug: 312680558
Test: ExifInterfaceTest
Change-Id: Ibec7f06d8cfe2c7cd1edf029e32b002ce8e2e22b
M exifinterface/exifinterface/src/main/java/androidx/exifinterface/media/ExifInterface.java
https://android-review.googlesource.com/3039227
Branch: androidx-main
commit c23003716636d5c161e9b8c5d139ebbde0b7c8b5
Author: Ian Baker <ibaker@google.com>
Date: Wed Apr 10 17:03:20 2024
Split GPS_TIMESTAMP handling from the rest of the backwards compat rational tags
This tag has different special handling to the rest in this set, so it
doesn't really make sense to include it here.
Bug: 312680558
Test: ExifInterfaceTest
Change-Id: Ibec7f06d8cfe2c7cd1edf029e32b002ce8e2e22b
M exifinterface/exifinterface/src/main/java/androidx/exifinterface/media/ExifInterface.java
su...@google.com
Project: platform/frameworks/support
Branch: androidx-main
commit 34755e56581a1d2b474c2e556eab6b7c587aa116
Author: Ian Baker <ibaker@google.com>
Date: Wed Apr 03 14:10:27 2024
Improve precision of ExifInterface double -> rational conversion
Bug: 312680558
Test: ExifInterfaceTest
Change-Id: Iafd9736aab51fc627a7f25a11b9384b5008fb9bf
M exifinterface/exifinterface/src/androidTest/java/androidx/exifinterface/media/ExifInterfaceTest.java
M exifinterface/exifinterface/src/main/java/androidx/exifinterface/media/ExifInterface.java
https://android-review.googlesource.com/3025043
Branch: androidx-main
commit 34755e56581a1d2b474c2e556eab6b7c587aa116
Author: Ian Baker <ibaker@google.com>
Date: Wed Apr 03 14:10:27 2024
Improve precision of ExifInterface double -> rational conversion
Bug: 312680558
Test: ExifInterfaceTest
Change-Id: Iafd9736aab51fc627a7f25a11b9384b5008fb9bf
M exifinterface/exifinterface/src/androidTest/java/androidx/exifinterface/media/ExifInterfaceTest.java
M exifinterface/exifinterface/src/main/java/androidx/exifinterface/media/ExifInterface.java
dr...@gmail.com
Project: platform/frameworks/support
Branch: androidx-main
commit 67282b9c5804e5b8bb28993e57940b322b963988
Author: Ian Baker <ibaker@google.com>
Date: Tue Apr 09 17:30:03 2024
Document ExifInterface 'rational' attributes returned as decimals
These specific attributes have special handling, for backwards
compatibility with the implementation of ExifInterface that preceded the
platform android.media.ExifInterface. See more context in this
internal code review comment from 2016:
http://ag/c/platform/frameworks/base/+/909922/2..9/api/current.txt#b20093
Also add tests for this handling, including the current behaviour of
rejecting/ignoring the 'correct' rational format when passed to
setAttribute(String, String). A follow-up change adds support for this
format (and updates these tests to reflect this).
Bug: 312680558
Test: ExifInterfaceTest
Change-Id: Ia09c2956f0f80279108ccf872174eb98214a38a8
M exifinterface/exifinterface/src/androidTest/java/androidx/exifinterface/media/ExifInterfaceTest.java
M exifinterface/exifinterface/src/main/java/androidx/exifinterface/media/ExifInterface.java
https://android-review.googlesource.com/3037113
Branch: androidx-main
commit 67282b9c5804e5b8bb28993e57940b322b963988
Author: Ian Baker <ibaker@google.com>
Date: Tue Apr 09 17:30:03 2024
Document ExifInterface 'rational' attributes returned as decimals
These specific attributes have special handling, for backwards
compatibility with the implementation of ExifInterface that preceded the
platform android.media.ExifInterface. See more context in this
internal code review comment from 2016:
Also add tests for this handling, including the current behaviour of
rejecting/ignoring the 'correct' rational format when passed to
setAttribute(String, String). A follow-up change adds support for this
format (and updates these tests to reflect this).
Bug: 312680558
Test: ExifInterfaceTest
Change-Id: Ia09c2956f0f80279108ccf872174eb98214a38a8
M exifinterface/exifinterface/src/androidTest/java/androidx/exifinterface/media/ExifInterfaceTest.java
M exifinterface/exifinterface/src/main/java/androidx/exifinterface/media/ExifInterface.java
su...@google.com
The following release(s) address this bug.It is possible this bug has only been partially addressed:
androidx.exifinterface:exifinterface:1.4.0-alpha01
dr...@gmail.com
OK I used androidx.work.Configuration.Builder() instead
dr...@gmail.com
User's device is a Samsung Galaxy S3
dr...@gmail.com
Where can I send a logcat from the user? There isn't anything of any sensitive nature so far as I can tell, but best not to post it here.
su...@google.com
You can send the logs here; I just mean I can't advise you about collection.
dr...@gmail.com
I'm attaching some logs which may be of interest. It includes the extra WorkManager logging you describe above, plus some random bits of logging from my own code (though I've removed quite a bit to avoid overkill here). I've added some annotations to note where the user did various actions (I'm guessing a little but fairly sure) to add some context.
The interest bit starts from "01-29 20:51:44.715"
The interest bit starts from "01-29 20:51:44.715"
ra...@google.com
I looked at the logs, and there are a lot of Worker cancellations happening. Are you explicitly cancelling work or using Existing{Periodic}WorkPolicy.REPLACE ?
Can you send us a trimmed down sample of how Workers are being enqueued for your app ?
Can you send us a trimmed down sample of how Workers are being enqueued for your app ?
ra...@google.com
Sorry, I see that you are using unique work. Looking into this further.
dr...@gmail.com
I don't think I'm doing much out of the ordinary when scheduling the periodic work... basically as follows (leaving in the logging that corresponds to what you see in the logcat, and removing some of the value fetching logic, e.g. fetching values from SharedPrefs etc). Entry point is e.g. schedulePeriodicWork(1234, "some-trigger");
static void schedulePeriodicWork(int appWidgetId, String trigger) {
Log.d(TAG, "schedulePeriodicWork for " + appWidgetId);
String name = getPeriodicName(appWidgetId);
long interval = getInterval();
Constraints constraints = getConstraints("periodic");
Data inputData = getPeriodicInputData(appWidgetId, trigger);
PeriodicWorkRequest workRequest = getPeriodicWorkRequest(appWidgetId, interval, constraints, inputData);
WorkManager workManager = WorkManager.getInstance();
workManager.enqueueUniquePeriodicWork(name, ExistingPeriodicWorkPolicy.REPLACE, workRequest);
}
private static String getPeriodicName(int appWidgetId) {
return "periodic-" + appWidgetId;
}
private static long getInterval() {
return 15 * 60 * 1000;
}
private static Constraints getConstraints(String method) {
Log.d(TAG, "creating Constraints for " + method);
Constraints.Builder constraintsBuilder = new Constraints.Builder();
Log.d(TAG, "adding network constraint");
constraintsBuilder.setRequiredNetworkType(NetworkType.CONNECTED);
return constraintsBuilder.build();
}
private static PeriodicWorkRequest getPeriodicWorkRequest(int appWidgetId, long interval, Constraints constraints, Data inputData) {
String workTag = getWorkTag(appWidgetId);
Log.d(TAG, "creating PeriodicWorkRequest with tag " + workTag + " and with interval " + interval + " ms");
PeriodicWorkRequest.Builder workRequestBuilder = new PeriodicWorkRequest.Builder(MeteogramWorker.class, interval, TimeUnit.MILLISECONDS);
workRequestBuilder.setConstraints(constraints);
workRequestBuilder.setInputData(inputData);
workRequestBuilder.addTag(workTag);
workRequestBuilder.addTag(PERIODIC);
return workRequestBuilder.build();
}
private static Data getPeriodicInputData(int appWidgetId, String trigger) {
Log.d(TAG, "creating Data");
Data.Builder dataBuilder = new Data.Builder();
dataBuilder.putInt(AppWidgetManager.EXTRA_APPWIDGET_ID, appWidgetId);
dataBuilder.putString(trigger);
dataBuilder.putString("method", "periodic");
return dataBuilder.build();
}
private static String getWorkTag(int appWidgetId) {
return "widget-" + appWidgetId;
}
static void schedulePeriodicWork(int appWidgetId, String trigger) {
Log.d(TAG, "schedulePeriodicWork for " + appWidgetId);
String name = getPeriodicName(appWidgetId);
long interval = getInterval();
Constraints constraints = getConstraints("periodic");
Data inputData = getPeriodicInputData(appWidgetId, trigger);
PeriodicWorkRequest workRequest = getPeriodicWorkRequest(appWidgetId, interval, constraints, inputData);
WorkManager workManager = WorkManager.getInstance();
workManager.enqueueUniquePeriodicWork(name, ExistingPeriodicWorkPolicy.REPLACE, workRequest);
}
private static String getPeriodicName(int appWidgetId) {
return "periodic-" + appWidgetId;
}
private static long getInterval() {
return 15 * 60 * 1000;
}
private static Constraints getConstraints(String method) {
Log.d(TAG, "creating Constraints for " + method);
Constraints.Builder constraintsBuilder = new Constraints.Builder();
Log.d(TAG, "adding network constraint");
constraintsBuilder.setRequiredNetworkType(NetworkType.CONNECTED);
return constraintsBuilder.build();
}
private static PeriodicWorkRequest getPeriodicWorkRequest(int appWidgetId, long interval, Constraints constraints, Data inputData) {
String workTag = getWorkTag(appWidgetId);
Log.d(TAG, "creating PeriodicWorkRequest with tag " + workTag + " and with interval " + interval + " ms");
PeriodicWorkRequest.Builder workRequestBuilder = new PeriodicWorkRequest.Builder(MeteogramWorker.class, interval, TimeUnit.MILLISECONDS);
workRequestBuilder.setConstraints(constraints);
workRequestBuilder.setInputData(inputData);
workRequestBuilder.addTag(workTag);
workRequestBuilder.addTag(PERIODIC);
return workRequestBuilder.build();
}
private static Data getPeriodicInputData(int appWidgetId, String trigger) {
Log.d(TAG, "creating Data");
Data.Builder dataBuilder = new Data.Builder();
dataBuilder.putInt(AppWidgetManager.EXTRA_APPWIDGET_ID, appWidgetId);
dataBuilder.putString(trigger);
dataBuilder.putString("method", "periodic");
return dataBuilder.build();
}
private static String getWorkTag(int appWidgetId) {
return "widget-" + appWidgetId;
}
dr...@gmail.com
Presumably there is some significance in the log entries around the time that the 15 min periodic work is due to run -- if there had been network available -- i.e. around 21:07 ? i.e. the ones that refer to failed linking and resolving of work-related classes? Examples:
01-29 21:07:01.245 W/dalvikvm(29185): Unable to resolve superclass of Landroidx/work/impl/background/systemjob/SystemJobService; (90)
01-29 21:07:01.245 W/dalvikvm(29185): Link of class 'Landroidx/work/impl/background/systemjob/SystemJobService;' failed
01-29 21:07:01.245 E/dalvikvm(29185): Could not find class 'androidx.work.impl.background.systemjob.SystemJobService', referenced from method androidx.work.impl.Schedulers.createBestAvailableBackgroundScheduler
01-29 21:07:01.245 W/dalvikvm(29185): VFY: unable to resolve const-class 2971 (Landroidx/work/impl/background/systemjob/SystemJobService;) in Landroidx/work/impl/Schedulers;
01-29 21:07:01.345 W/dalvikvm(29185): Unable to resolve superclass of Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback; (341)
01-29 21:07:01.345 W/dalvikvm(29185): Link of class 'Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback;' failed
01-29 21:07:01.350 E/dalvikvm(29185): Could not find class 'androidx.work.impl.constraints.trackers.NetworkStateTracker$NetworkStateCallback', referenced from method androidx.work.impl.constraints.trackers.NetworkStateTracker.<init>
01-29 21:07:01.350 W/dalvikvm(29185): VFY: unable to resolve new-instance 2994 (Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback;) in Landroidx/work/impl/constraints/trackers/NetworkStateTracker;
01-29 21:07:01.355 I/dalvikvm(29185): Could not find method android.net.ConnectivityManager.getActiveNetwork, referenced from method androidx.work.impl.constraints.trackers.NetworkStateTracker.isActiveNetworkValidated
01-29 21:07:01.355 W/dalvikvm(29185): VFY: unable to resolve virtual method 1865: Landroid/net/ConnectivityManager;.getActiveNetwork ()Landroid/net/Network;
01-29 21:07:01.355 D/dalvikvm(29185): VFY: replacing opcode 0x6e at 0x000a
01-29 21:07:01.360 W/dalvikvm(29185): Unable to resolve superclass of Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback; (341)
01-29 21:07:01.360 W/dalvikvm(29185): Link of class 'Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback;' failed
01-29 21:07:01.360 I/dalvikvm(29185): Could not find method android.net.ConnectivityManager.registerDefaultNetworkCallback, referenced from method androidx.work.impl.constraints.trackers.NetworkStateTracker.startTracking
01-29 21:07:01.360 W/dalvikvm(29185): VFY: unable to resolve virtual method 1871: Landroid/net/ConnectivityManager;.registerDefaultNetworkCallback (Landroid/net/ConnectivityManager$NetworkCallback;)V
01-29 21:07:01.365 W/dalvikvm(29185): Unable to resolve superclass of Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback; (341)
01-29 21:07:01.365 W/dalvikvm(29185): Link of class 'Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback;' failed
01-29 21:07:01.365 I/dalvikvm(29185): Could not find method android.net.ConnectivityManager.unregisterNetworkCallback, referenced from method androidx.work.impl.constraints.trackers.NetworkStateTracker.stopTracking
01-29 21:07:01.365 W/dalvikvm(29185): VFY: unable to resolve virtual method 1872: Landroid/net/ConnectivityManager;.unregisterNetworkCallback (Landroid/net/ConnectivityManager$NetworkCallback;)V
01-29 21:07:01.365 D/dalvikvm(29185): VFY: replacing opcode 0x6e at 0x0018
01-29 21:07:01.370 W/dalvikvm(29185): Unable to resolve superclass of Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback; (341)
01-29 21:07:01.370 W/dalvikvm(29185): Link of class 'Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback;' failed
01-29 21:07:01.370 D/dalvikvm(29185): DexOpt: unable to opt direct call 0x593e at 0x17 in Landroidx/work/impl/constraints/trackers/NetworkStateTracker;.<init>
01-29 21:07:01.245 W/dalvikvm(29185): Unable to resolve superclass of Landroidx/work/impl/background/systemjob/SystemJobService; (90)
01-29 21:07:01.245 W/dalvikvm(29185): Link of class 'Landroidx/work/impl/background/systemjob/SystemJobService;' failed
01-29 21:07:01.245 E/dalvikvm(29185): Could not find class 'androidx.work.impl.background.systemjob.SystemJobService', referenced from method androidx.work.impl.Schedulers.createBestAvailableBackgroundScheduler
01-29 21:07:01.245 W/dalvikvm(29185): VFY: unable to resolve const-class 2971 (Landroidx/work/impl/background/systemjob/SystemJobService;) in Landroidx/work/impl/Schedulers;
01-29 21:07:01.345 W/dalvikvm(29185): Unable to resolve superclass of Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback; (341)
01-29 21:07:01.345 W/dalvikvm(29185): Link of class 'Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback;' failed
01-29 21:07:01.350 E/dalvikvm(29185): Could not find class 'androidx.work.impl.constraints.trackers.NetworkStateTracker$NetworkStateCallback', referenced from method androidx.work.impl.constraints.trackers.NetworkStateTracker.<init>
01-29 21:07:01.350 W/dalvikvm(29185): VFY: unable to resolve new-instance 2994 (Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback;) in Landroidx/work/impl/constraints/trackers/NetworkStateTracker;
01-29 21:07:01.355 I/dalvikvm(29185): Could not find method android.net.ConnectivityManager.getActiveNetwork, referenced from method androidx.work.impl.constraints.trackers.NetworkStateTracker.isActiveNetworkValidated
01-29 21:07:01.355 W/dalvikvm(29185): VFY: unable to resolve virtual method 1865: Landroid/net/ConnectivityManager;.getActiveNetwork ()Landroid/net/Network;
01-29 21:07:01.355 D/dalvikvm(29185): VFY: replacing opcode 0x6e at 0x000a
01-29 21:07:01.360 W/dalvikvm(29185): Unable to resolve superclass of Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback; (341)
01-29 21:07:01.360 W/dalvikvm(29185): Link of class 'Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback;' failed
01-29 21:07:01.360 I/dalvikvm(29185): Could not find method android.net.ConnectivityManager.registerDefaultNetworkCallback, referenced from method androidx.work.impl.constraints.trackers.NetworkStateTracker.startTracking
01-29 21:07:01.360 W/dalvikvm(29185): VFY: unable to resolve virtual method 1871: Landroid/net/ConnectivityManager;.registerDefaultNetworkCallback (Landroid/net/ConnectivityManager$NetworkCallback;)V
01-29 21:07:01.365 W/dalvikvm(29185): Unable to resolve superclass of Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback; (341)
01-29 21:07:01.365 W/dalvikvm(29185): Link of class 'Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback;' failed
01-29 21:07:01.365 I/dalvikvm(29185): Could not find method android.net.ConnectivityManager.unregisterNetworkCallback, referenced from method androidx.work.impl.constraints.trackers.NetworkStateTracker.stopTracking
01-29 21:07:01.365 W/dalvikvm(29185): VFY: unable to resolve virtual method 1872: Landroid/net/ConnectivityManager;.unregisterNetworkCallback (Landroid/net/ConnectivityManager$NetworkCallback;)V
01-29 21:07:01.365 D/dalvikvm(29185): VFY: replacing opcode 0x6e at 0x0018
01-29 21:07:01.370 W/dalvikvm(29185): Unable to resolve superclass of Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback; (341)
01-29 21:07:01.370 W/dalvikvm(29185): Link of class 'Landroidx/work/impl/constraints/trackers/NetworkStateTracker$NetworkStateCallback;' failed
01-29 21:07:01.370 D/dalvikvm(29185): DexOpt: unable to opt direct call 0x593e at 0x17 in Landroidx/work/impl/constraints/trackers/NetworkStateTracker;.<init>
dr...@gmail.com
And at the time the logs are taken by the user, the app dumps the current work queue, and sure enough there is a periodic work still enqueued (but this periodic work doesn't run when network has been restored and never seems to run again)... this is the log entry here:
01-29 21:11:33.875 D/Meteogram_ConfigActvty(29556): ********** LOG OF WORK QUEUE **********
01-29 21:11:34.175 D/Meteogram_Worker(29556): workInfo: WorkInfo{mId='8eaea234-7001-479e-ae88-2d628f57a62b', mState=ENQUEUED, mOutputData=androidx.work.Data@0, mTags=[widget-43443, com.cloud3squared.meteogram.MeteogramWorker, periodic]}
01-29 21:11:34.175 D/Meteogram_Worker(29556): workInfo: WorkInfo{mId='c43771c7-6b71-49fb-a2ee-c8486b37b798', mState=SUCCEEDED, mOutputData=androidx.work.Data@0, mTags=[widget-43443, com.cloud3squared.meteogram.MeteogramWorker, onetime]}
01-29 21:11:34.175 D/Meteogram_ConfigActvty(29556): ********** END OF WORK QUEUE **********
The above is logged by the following function, with the widget id passed in to get the tag (same method as in previous post), and filtering the work on this tag:
static void logWorkQueue(int appWidgetId) {
String tag = getWorkTag(appWidgetId);
WorkManager workManager = WorkManager.getInstance();
ListenableFuture<List<WorkInfo>> workInfos = workManager.getWorkInfosByTag(tag);
try {
List<WorkInfo> workInfoList = workInfos.get();
for (WorkInfo workInfo : workInfoList) {
Log.d(TAG, "workInfo: " + workInfo.toString());
}
} catch (ExecutionException e) {
e.printStackTrace();
} catch (InterruptedException e) {
e.printStackTrace();
}
}
01-29 21:11:33.875 D/Meteogram_ConfigActvty(29556): ********** LOG OF WORK QUEUE **********
01-29 21:11:34.175 D/Meteogram_Worker(29556): workInfo: WorkInfo{mId='8eaea234-7001-479e-ae88-2d628f57a62b', mState=ENQUEUED, mOutputData=androidx.work.Data@0, mTags=[widget-43443, com.cloud3squared.meteogram.MeteogramWorker, periodic]}
01-29 21:11:34.175 D/Meteogram_Worker(29556): workInfo: WorkInfo{mId='c43771c7-6b71-49fb-a2ee-c8486b37b798', mState=SUCCEEDED, mOutputData=androidx.work.Data@0, mTags=[widget-43443, com.cloud3squared.meteogram.MeteogramWorker, onetime]}
01-29 21:11:34.175 D/Meteogram_ConfigActvty(29556): ********** END OF WORK QUEUE **********
The above is logged by the following function, with the widget id passed in to get the tag (same method as in previous post), and filtering the work on this tag:
static void logWorkQueue(int appWidgetId) {
String tag = getWorkTag(appWidgetId);
WorkManager workManager = WorkManager.getInstance();
ListenableFuture<List<WorkInfo>> workInfos = workManager.getWorkInfosByTag(tag);
try {
List<WorkInfo> workInfoList = workInfos.get();
for (WorkInfo workInfo : workInfoList) {
Log.d(TAG, "workInfo: " + workInfo.toString());
}
} catch (ExecutionException e) {
e.printStackTrace();
} catch (InterruptedException e) {
e.printStackTrace();
}
}
dr...@gmail.com
Further update: it's just possible that this isn't specifically related to the network constraint. This user has now reported that a even a non-network-constrained periodic work seems to have stopped (as manifested by the associated widget no longer auto updating). I don't have logs for this, but maybe some of those log entries around 21:07 from the previous logcat might also be occurring even for periodic work that is not network constrained? Until now, the non-network-constrained periodic work does however seem to be more reliable... network constrained periodic work seems consistently to stop after a period without network.
ra...@google.com
Thanks for the details. I should have updated the thread yesterday. I think I know what might be going on.
I have a pending CL as well. It should be fixed in the next beta.
https://android-review.googlesource.com/c/platform/frameworks/support/+/889839
I have a pending CL as well. It should be fixed in the next beta.
dr...@gmail.com
This is excellent news... thanks for checking it out so carefully, and fingers crossed... look forward to the next beta and will report back either way.
Any ETA on the next beta?
Keep up the good work on this really useful library!
Any ETA on the next beta?
Keep up the good work on this really useful library!
ap...@google.com
Project: platform/frameworks/support
Branch: androidx-master-dev
commit 177837514245d5bb24cc8e9bc27f20503e23e308
Author: Rahul Ravikumar <rahulrav@google.com>
Date: Tue Jan 29 17:50:14 2019
Fixes ConstraintsCommandHandler that correctly enables and disables proxies.
* ConstraintsCommandHandler was only looking at work that was eligible to be scheduled.
This is incorrect, as we may have Workers that are scheduled, but are pending execution due
to an unmet constraint. We need to look at all scheduled work which is unfinished.
* The only reason why this worked before with integration tests was due to one of 2 reasons:
* The process was in the foreground anyway, and there was an active WorkConstraintTracker.
* Enabling / disabling airplane mode (to test Network Constraints) would have caused a
TIME_SET broadcast in some cases where we reschedule everything (RescheduleReceiver).
Test: Updated SystemAlarmDispatcherTests & integration tests on API 22 with the Battery charging
Constraint that has no other side effects.
Change-Id: Ib973931b47be915dd8f533e1e651b6c1a29843f9
Fixes:
M work/workmanager/src/androidTest/java/androidx/work/impl/background/systemalarm/SystemAlarmDispatcherTest.java
M work/workmanager/src/main/java/androidx/work/impl/background/systemalarm/ConstraintsCommandHandler.java
M work/workmanager/src/main/java/androidx/work/impl/background/systemalarm/RescheduleReceiver.java
M work/workmanager/src/main/java/androidx/work/impl/model/WorkSpecDao.java
https://android-review.googlesource.com/889839
https://goto.google.com/android-sha1/177837514245d5bb24cc8e9bc27f20503e23e308
Branch: androidx-master-dev
commit 177837514245d5bb24cc8e9bc27f20503e23e308
Author: Rahul Ravikumar <rahulrav@google.com>
Date: Tue Jan 29 17:50:14 2019
Fixes ConstraintsCommandHandler that correctly enables and disables proxies.
* ConstraintsCommandHandler was only looking at work that was eligible to be scheduled.
This is incorrect, as we may have Workers that are scheduled, but are pending execution due
to an unmet constraint. We need to look at all scheduled work which is unfinished.
* The only reason why this worked before with integration tests was due to one of 2 reasons:
* The process was in the foreground anyway, and there was an active WorkConstraintTracker.
* Enabling / disabling airplane mode (to test Network Constraints) would have caused a
TIME_SET broadcast in some cases where we reschedule everything (RescheduleReceiver).
Test: Updated SystemAlarmDispatcherTests & integration tests on API 22 with the Battery charging
Constraint that has no other side effects.
Change-Id: Ib973931b47be915dd8f533e1e651b6c1a29843f9
Fixes:
M work/workmanager/src/androidTest/java/androidx/work/impl/background/systemalarm/SystemAlarmDispatcherTest.java
M work/workmanager/src/main/java/androidx/work/impl/background/systemalarm/ConstraintsCommandHandler.java
M work/workmanager/src/main/java/androidx/work/impl/background/systemalarm/RescheduleReceiver.java
M work/workmanager/src/main/java/androidx/work/impl/model/WorkSpecDao.java
dr...@gmail.com
Any ETA for beta04? Am desperate to try it out..
ra...@google.com
Looking at early next week.
dr...@gmail.com
OK, thanks!
dr...@gmail.com
I'm still seeing this problem, or seeing it again. I'm monitoring (at a server) requests from the device of the same user (Android 4.3), and can see that a periodic work request seems to run OK for a time, but when the device is idle and without network, when the device is given network again, not only does the late work not run, but no work ever seems to run again. And a log output of all work does still show that a periodic work is enqueued, but it just never seems to run again.
Are the tests you ran when fixing this before still working? Or has something subsequently messed it up? Or maybe I'm seeing another issue altogether.
Are the tests you ran when fixing this before still working? Or has something subsequently messed it up? Or maybe I'm seeing another issue altogether.
su...@google.com
Please give us a sample project. I think that's the simplest way for us to take a look at exactly what's happening for you. Which device are you running this on?
dr...@gmail.com
Device is as per #16 -- Samsung Galaxy S3 running Android 4.3
su...@google.com
Can you reproduce the same behavior using a stock Android device/emulator?
dr...@gmail.com
Not as yet; am trying now.
dr...@gmail.com
Is there any way of querying a bit more information about enqueued work requests? The most information I can get at the moment is something like:
02-15 17:37:31.535 D/My_Worker(11599): workInfo: WorkInfo{mId='00db2ea7-07d6-42a1-a506-a26ff8e3217d', mState=ENQUEUED, mOutputData=androidx.work.Data@0, mTags=[com.example.myapp.MyWorker, widget-43806, periodic]}
02-15 17:37:31.535 D/My_Worker(11599): workInfo: WorkInfo{mId='08bce448-5d4a-4a17-89d2-6fdce6ef1091', mState=SUCCEEDED, mOutputData=androidx.work.Data@0, mTags=[com.example.myapp.MyWorker, widget-43806, backstop]}
And the only reason I can even tell if the work item is periodic or not is because I tag it with 'periodic' if it is. Otherwise, all I get is a work ID and a state... would be really handy to know when it last ran, when it is due to run next, etc. Would be very useful not least for debugging purposes.
As suggested:https://issuetracker.google.com/issues/123222823
02-15 17:37:31.535 D/My_Worker(11599): workInfo: WorkInfo{mId='00db2ea7-07d6-42a1-a506-a26ff8e3217d', mState=ENQUEUED, mOutputData=androidx.work.Data@0, mTags=[com.example.myapp.MyWorker, widget-43806, periodic]}
02-15 17:37:31.535 D/My_Worker(11599): workInfo: WorkInfo{mId='08bce448-5d4a-4a17-89d2-6fdce6ef1091', mState=SUCCEEDED, mOutputData=androidx.work.Data@0, mTags=[com.example.myapp.MyWorker, widget-43806, backstop]}
And the only reason I can even tell if the work item is periodic or not is because I tag it with 'periodic' if it is. Otherwise, all I get is a work ID and a state... would be really handy to know when it last ran, when it is due to run next, etc. Would be very useful not least for debugging purposes.
As suggested:
ra...@google.com
You need to enable verbose logs. That will tell us a lot more.
ra...@google.com
Also, if you are going into a SUCCEEDED state, that mean your Worker is actually not periodic. PeriodicWork never goes into a terminal state unless it has been cancelled.
It always goes back to ENQUEUED for the next interval.
It always goes back to ENQUEUED for the next interval.
dr...@gmail.com
As per #9 above. Yes, the 4.3 user is currently running a test version with this verbose logging enabled to see if I can get something interesting from it.
ra...@google.com
For reference all WorkManager logs are prefixed with a "WM-".
dr...@gmail.com
#39: indeed, but the SUCCEEDED entry is a onetime worker... it is not tagged with 'periodic' but only 'backstop' (which is a onetime request).
dr...@gmail.com
I've seen this behaviour now on the 4.3 emulator. I started a periodic work request (for updating a widget) with network constraint and interval of one hour (flex of 30 mins). I put the emulator into airplane mode and came back some time later. On disabling airplane mode the widget did update immediately but the trigger was ON_ENABLED for the widget and not the late work request. Thereafter, I left the widget for an hour, and nothing happened... the periodic work that was meant to trigger an update hasn't happened. I meant to dump the alarm state with "adb shell dumpsys alarm" but unfortunately I reset the widget before doing so. Will next time. Sorry it's a bit nebulous thus far... I will try to bring more concrete information next time but there's definitely still something not right with network-constrained periodic work on Android 4.3.
su...@google.com
Yes, please send us a sample project when you have it.
dr...@gmail.com
I'll try, but am short of time over next few days. Tempting just to set minsdk to 21 and be done with it!
dr...@gmail.com
I have some logs to post... would that be of assistance in lieu of a sample project for now?
ra...@google.com
Yes, please send them
dr...@gmail.com
Logs attached, from the user's Android 4.3 device. During the period in which the logs were generated, the periodic work concerned should have fired (to cause a widget to update) at least twice but failed to do so. The periodic work was on a 30 minute interval, with 15 minute flex interval. With network constraint. After enqueuing the periodic work, the device was without network for a time, then network was restored. But periodic work failed to trigger. I schedule the periodic work basically as described in #22 *except* that I now use a flex interval (to address a double running of work as per another issue).
There seems to be lots of "D/WM-" stuff in there that refers to constraints... hopefully something of interest.
There seems to be lots of "D/WM-" stuff in there that refers to constraints... hopefully something of interest.
dr...@gmail.com
Some further information which may be of interest...
To see if it made a difference, I went back to NOT using a flexInterval, i.e. using:
workRequestBuilder = new PeriodicWorkRequest.Builder(MeteogramWorker.class, interval, TimeUnit.MILLISECONDS);
INSTEAD of:
workRequestBuilder = new PeriodicWorkRequest.Builder(MeteogramWorker.class, interval, TimeUnit.MILLISECONDS, flexInterval, TimeUnit.MILLISECONDS);
And without using flexInterval, behaviour seems to be FAR more reliable so far. The periodic work (with network constraint) has so far survived some degree of testing (on the user device): letting the periodic work fire a few times, then turning off network for one or more scheduled firings, then network back on... and each time so far the "missed" work runs straight away.
It's far from an extensive test yet, but it seems like it can't be coincidence... the above change (to NOT use flexInterval) is all I've changed, and it is performing better so far.
After *this current* issue (i.e. #123379508) was marked fixed on 30 Jan, a change was made to WorkManager flexInterval behaviour on 13 Feb as per the following:
https://issuetracker.google.com/issues/124274584
Would it have anything to do with that? Between #123379508 being fixed (30 Jan) and #124274584 being fixed (13 Feb), I think that things were going well. It seemed to be after #124274584 was fixed that things went downhill again. Again, I can't be certain, but it's a lead anyway.
P.S. the only reason I started using flexInterval in the first place was to address the issue reported here:
https://issuetracker.google.com/issues/123804615#comment8
To see if it made a difference, I went back to NOT using a flexInterval, i.e. using:
workRequestBuilder = new PeriodicWorkRequest.Builder(MeteogramWorker.class, interval, TimeUnit.MILLISECONDS);
INSTEAD of:
workRequestBuilder = new PeriodicWorkRequest.Builder(MeteogramWorker.class, interval, TimeUnit.MILLISECONDS, flexInterval, TimeUnit.MILLISECONDS);
And without using flexInterval, behaviour seems to be FAR more reliable so far. The periodic work (with network constraint) has so far survived some degree of testing (on the user device): letting the periodic work fire a few times, then turning off network for one or more scheduled firings, then network back on... and each time so far the "missed" work runs straight away.
It's far from an extensive test yet, but it seems like it can't be coincidence... the above change (to NOT use flexInterval) is all I've changed, and it is performing better so far.
After *this current* issue (i.e. #123379508) was marked fixed on 30 Jan, a change was made to WorkManager flexInterval behaviour on 13 Feb as per the following:
Would it have anything to do with that? Between #123379508 being fixed (30 Jan) and #124274584 being fixed (13 Feb), I think that things were going well. It seemed to be after #124274584 was fixed that things went downhill again. Again, I can't be certain, but it's a lead anyway.
P.S. the only reason I started using flexInterval in the first place was to address the issue reported here:
dr...@gmail.com
BTW the logs in #48 were BEFORE I made the change mentioned in #49, i.e. using flexInterval
ra...@google.com
I looked at the logs. It looks like the ConstraintTracker correctly tries to start the work, but the device subsequently reports that the constraints are unmet when trying to run the Worker.
02-17 14:02:25.255 D/WM-ConstraintTracker( 1608): NetworkStateTracker: initial state = [ Connected=false Validated=false Metered=false NotRoaming=false ]. This happens twice, like you described.
This is expected behavior. I think your disabling of flex has nothing to do with why the Worker was running when you had flex. I think the device does not have access to a reliable network as far as I can tell.
02-17 14:02:25.255 D/WM-ConstraintTracker( 1608): NetworkStateTracker: initial state = [ Connected=false Validated=false Metered=false NotRoaming=false ]. This happens twice, like you described.
This is expected behavior. I think your disabling of flex has nothing to do with why the Worker was running when you had flex. I think the device does not have access to a reliable network as far as I can tell.
dr...@gmail.com
It's a WiFi network... not saying that is necessary "reliable" but it surely is unlikely to be consistently unreliable?
And how do you explain why NOT specifying a flexInterval results in completely reliable periodic behaviour? While specifying a flexInterval makes it fall apart?
I don't follow your comment about expected behaviour... in the period of the logs, the device had no WiFi for at least two expected periodic runs, but didn't run because there was no network. That's expected behaviour, yes. What is not expected is that even when network was restored, the work did not run, ever again. That is when specifying a flexInterval.
But when not specifying a flexInterval, it all works smoothly... that doesn't make sense does it?
Am getting reports in now from said user... it's running like clockwork with the version that doesn't specify flexInterval when setting up the periodic work request.
And how do you explain why NOT specifying a flexInterval results in completely reliable periodic behaviour? While specifying a flexInterval makes it fall apart?
I don't follow your comment about expected behaviour... in the period of the logs, the device had no WiFi for at least two expected periodic runs, but didn't run because there was no network. That's expected behaviour, yes. What is not expected is that even when network was restored, the work did not run, ever again. That is when specifying a flexInterval.
But when not specifying a flexInterval, it all works smoothly... that doesn't make sense does it?
Am getting reports in now from said user... it's running like clockwork with the version that doesn't specify flexInterval when setting up the periodic work request.
ra...@google.com
Specifying flex does nothing except delay the Worker in the AlarmManager implementation.
There is absolutely no difference in how constraints are handled.
Also, from the logs that you attached, it is clear that the device was not connected to a network. That's what I am basing this on. (NetworkStateTracker: initial state = [ Connected=false Validated=false Metered=false NotRoaming=false ]).
If you still think there might be something else going on, I think the best thing to do is to send us a sample app to reproduce this on our end.
There is absolutely no difference in how constraints are handled.
Also, from the logs that you attached, it is clear that the device was not connected to a network. That's what I am basing this on. (NetworkStateTracker: initial state = [ Connected=false Validated=false Metered=false NotRoaming=false ]).
If you still think there might be something else going on, I think the best thing to do is to send us a sample app to reproduce this on our end.
dr...@gmail.com
There are two such logs entries (one of which you quote above) that say "Connected=false".
But there is a third one, later, that says "Connected=true":
02-17 14:40:50.345 D/WM-ConstraintTracker( 3798): NetworkStateTracker: initial state = [ Connected=true Validated=false Metered=false NotRoaming=true ]
And then immediately after:
02-17 14:40:50.345 D/WM-WorkConstraintsTrack( 3798): Constraints met for 635bfec6-81c9-499a-a9d2-5e273f07573c
So why did the work not run?
But there is a third one, later, that says "Connected=true":
02-17 14:40:50.345 D/WM-ConstraintTracker( 3798): NetworkStateTracker: initial state = [ Connected=true Validated=false Metered=false NotRoaming=true ]
And then immediately after:
02-17 14:40:50.345 D/WM-WorkConstraintsTrack( 3798): Constraints met for 635bfec6-81c9-499a-a9d2-5e273f07573c
So why did the work not run?
su...@google.com
So I think we're going very very deep into a bug that we cannot reproduce. Please send us a sample project.
dr...@gmail.com
Trouble is, I think this may be quite specific to that device. I can't reproduce it on the emulator (what I thought I was seeing in #43 was actually something else). So all we have to go on is the logs from the user device. I thought the D/WM- log entries would help... clearly not. Is it not possible to determine from those why the work constraints were met at 02-17 14:40:50.345 and yet the work did not execute?
dr...@gmail.com
Here is another instance, today, where the network-constrained periodic work (widget update) failed to run on the user's Android 4.3 device after turning the WiFi back on first thing this morning... see attached logs, with relevant entries below:
02-20 10:28:12.735 D/WM-ConstraintProxy( 1227): onReceive : Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x8000010 cmp=com.cloud3squared.meteogram.devpro/androidx.work.impl.background.systemalarm.ConstraintProxy$NetworkStateProxy (has extras) }
02-20 10:28:14.770 D/WM-ConstraintTracker( 1227): NetworkStateTracker: initial state = [ Connected=true Validated=false Metered=false NotRoaming=true ]
02-20 10:28:14.815 D/WM-WorkConstraintsTrack( 1227): Constraints met for 5d210711-4c14-43cb-b6ea-2a6de910d76a
And yet, after this, the work doesn't run... there are no log entries from the startWork() function of the associated Worker.
02-20 10:28:12.735 D/WM-ConstraintProxy( 1227): onReceive : Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x8000010 cmp=com.cloud3squared.meteogram.devpro/androidx.work.impl.background.systemalarm.ConstraintProxy$NetworkStateProxy (has extras) }
02-20 10:28:14.770 D/WM-ConstraintTracker( 1227): NetworkStateTracker: initial state = [ Connected=true Validated=false Metered=false NotRoaming=true ]
02-20 10:28:14.815 D/WM-WorkConstraintsTrack( 1227): Constraints met for 5d210711-4c14-43cb-b6ea-2a6de910d76a
And yet, after this, the work doesn't run... there are no log entries from the startWork() function of the associated Worker.
Description
I think my issue is unrelated, hence this new bug report.
I am applying a network constrain to my PeriodicWorkRequest:
// ...
constraintsBuilder.setRequiredNetworkType(NetworkType.CONNECTED);
// ...
Constraints constraints = constraintsBuilder.build();
// ...
periodicWorkRequestBuilder.setConstraints(constraints);
// ...
PeriodicWorkRequest = periodicWorkRequestBuilder.build();
The idea is of course that the periodic work will run only if there is network. If there isn't, it will wait until there is, and then perform the work, and the subsequent periodic work will be scheduled after that.
This all works very well based on my own tests. But I have *one* user of an older Android 4.3 device where things break down (there may be others... but only one is reporting it... certainly it is not widespread).
From what I can determine, with a network constraint applied to the periodic work as above, if the periodic work is scheduled to run at time when there is no network, it appears on this user device that it does not run, as expected (because if if did, a "retry" work request would be scheduled by my code, which it isn't).
But it also appears that it NEVER RUNS AGAIN. In other words, the periodic work seems to be enqueued still, but just never runs again. It's as if the restoration of network doesn't kick it into running, and so it never does, ever again.
When this user runs an alternative version of the app where the network constraint is NOT applied to the periodic work (instead applying Constraints.NONE), the periodic work appears to survive the network downtime, and carry on ticking. It does attempt to run without network, which I can tell because a onetime "retry" work is scheduled, which surfaces later.
I have tried to reproduce this on an Android 4.3 emulator to no avail... seems to work as expected. So, this may not be enough information to go on.
It's almost as if CONNECTIVITY_CHANGE is not being received (I assume that WorkManager uses this signal)... or not acted on.
We don't need to add any special permissions or anything to make CONNECTIVITY_CHANGE work on all devices?