How to fix NFC Extended Length Function issues?

Jayky · April 17, 2021, 1:45pm

Hello,

I’ve used the NFC function of my FP3+ for the first time. My use case was a connection to my personal ID card (by using the German app AusweisApp2). The connection was unstable, but possible. Unfortunately essential functions failed due to a connection issue.

I wrote to the developers of the App and got the answer that on LineageOS based systems there are problems with the Extended Length Function.

I have no idea what that means, but I am willing to try to fix it. So I am asking here for help. Does anyone have an idea how to fix that issue? I am glad for any suggestions.

Best regards
Jayky

adaschma · April 17, 2021, 4:18pm

I have a FP3 (without +) and successfully use the AusweisApp2. /e/ supports the NFC Extended Length function (under FP3). What Version of /e/OS do you have? I have the 0.15-20210313105774 (Android 9). What is your version of AusweisApp2? Mine is the 1.22.0 from f-droid.org. The AusweisApp2 has a “Gerät und Ausweis prüfen” function. What is that result? Mine looks like this:

Jayky · April 18, 2021, 6:51pm

Hi @adaschma,

first of all when I use the mentioned function, the result is the same as yours.
My version of the app is 1.22.0, my e/OS/ version is 0.15-20210317106351 (Android 10).

So as mentioned before it was hard to get a stable connection, but I managed it several times. And even though the “Gerät und Ausweis prüfen” function told me everything is fine, it wasn’t. I could enter the TransportPIN and enter two times a private PIN. But in the end it told me, that there is a connection error. When there is no connection at all, you are not able to enter anything. So I am puzzled…

adaschma · April 20, 2021, 11:17am

One difference is that you are on Android 10 and I’m still on Android 9. As the /e/ with Android 9 doesn’t support the new camera module downgrading to 9 isn’t really an option. I doubt that the problem is related to the Extended Length Function. That is more a configuration option and should either work or not and not cause a flaky result (but I am no expert).
Looking through the bug tracker I found: https://gitlab.e.foundation/e/backlog/-/issues/1501 Could you get the create get the log from your phone https://developer.android.com/studio/command-line/logcat (that is shortly after you have the problem with the NFC). Then we could see if it has the same source.

Jayky · April 21, 2021, 4:29pm

Hi,

thanks for the links. The bug report sounds really familiar to me.

So, I tried my very best to get a logcat report. I’ve used termux and started just the logcat command. Then I’ve activated NFC and started the AusweisApp2. First I’ve checked the connection. Again, everything was okay. Then I’ve tried to change the transport PIN and it was as described before. Then I’ve done the check again and it was okay, again. But then the app crashed, just stopped working. Also, I could not deactivate the NFC function anymore. So I just saved the logcat entry and had to restart the phone…

Here is the Entry:

~ $ logcat
--------- beginning of main
04-21 18:04:46.582 10916 10941 I AdrenoGLES: QUALCOMM build : 994be9a, I75b52107df
04-21 18:04:46.582 10916 10941 I AdrenoGLES: Build Date : 05/28/20
04-21 18:04:46.582 10916 10941 I AdrenoGLES: OpenGL ES Shader Compiler Version: EV031.27.05.10
04-21 18:04:46.582 10916 10941 I AdrenoGLES: Local Branch :
04-21 18:04:46.582 10916 10941 I AdrenoGLES: Remote Branch :
04-21 18:04:46.582 10916 10941 I AdrenoGLES: Remote Branch :
04-21 18:04:46.582 10916 10941 I AdrenoGLES: Reconstruct Branch :
04-21 18:04:46.582 10916 10941 I AdrenoGLES: Build Config : S L 8.0.12 AArch64
04-21 18:04:46.761 10916 10954 D CCodec : allocate(c2.android.vorbis.decoder)
04-21 18:04:46.766 10916 10941 I AdrenoGLES: PFP: 0x005ff112, ME: 0x005ff066
04-21 18:04:46.794 10916 10954 I Codec2Client: Available Codec2 services: “software”
04-21 18:04:46.795 10916 10954 I Codec2Client: Creating a Codec2 client to service “software”
04-21 18:04:46.875 10916 10954 I Codec2Client: Client to Codec2 service “software” created
04-21 18:04:46.881 10916 10941 W Gralloc3: mapper 3.x is not supported
04-21 18:04:46.940 10916 10941 I OpenGLRenderer: Davey! duration=703ms; Flags=1, IntendedVsync=175748049858766, Vsync=175748099858764, OldestInputEvent=9223372036854775807, NewestInputEvent=0, HandleInputStart=175748115382981, AnimationStart=175748115495741, PerformTraversalsStart=175748115507825, DrawStart=175748656967410, SyncQueued=175748691120174, SyncStart=175748695054497, IssueDrawCommandsStart=175748695269757, SwapBuffers=175748738620491, FrameCompleted=175748757253826, DequeueBufferDuration=1394000, QueueBufferDuration=737000,
04-21 18:04:46.955 10916 10916 W com.termux: type=1400 audit(0.0:3439): avc: granted { execute } for name=“login” dev=“mmcblk0p62” ino=533503 scontext=u:r:untrusted_app_27:s0:c227,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c227,c256,c512,c768 tclass=file app=com.termux
04-21 18:04:46.994 10916 10954 I CCodec : Created component [c2.android.vorbis.decoder]
04-21 18:04:46.996 10916 10954 D CCodecConfig: read media type: audio/vorbis
04-21 18:04:47.008 10916 10954 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.max-count.values
04-21 18:04:47.017 10916 10954 D ReflectedParamUpdater: extent() != 1 for single value type: output.subscribed-indices.values
04-21 18:04:47.017 10916 10954 D ReflectedParamUpdater: extent() != 1 for single value type: input.buffers.allocator-ids.values
04-21 18:04:47.018 10916 10954 D ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.allocator-ids.values
04-21 18:04:47.018 10916 10954 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.allocator-ids.values
04-21 18:04:47.019 10916 10954 D ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.pool-ids.values
04-21 18:04:47.020 10916 10954 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.pool-ids.values
04-21 18:04:47.027 10916 10954 I CCodecConfig: query failed after returning 7 values (BAD_INDEX)
04-21 18:04:47.027 10916 10954 D CCodecConfig: c2 config diff is Dict {
04-21 18:04:47.027 10916 10954 D CCodecConfig: c2::u32 coded.bitrate.value = 64000
04-21 18:04:47.027 10916 10954 D CCodecConfig: c2::u32 input.buffers.max-size.value = 32768
04-21 18:04:47.027 10916 10954 D CCodecConfig: c2::u32 input.delay.value = 0
04-21 18:04:47.027 10916 10954 D CCodecConfig: string input.media-type.value = “audio/vorbis”
04-21 18:04:47.027 10916 10954 D CCodecConfig: string output.media-type.value = “audio/raw”
04-21 18:04:47.027 10916 10954 D CCodecConfig: c2::u32 raw.channel-count.value = 1
04-21 18:04:47.027 10916 10954 D CCodecConfig: c2::u32 raw.sample-rate.value = 48000
04-21 18:04:47.027 10916 10954 D CCodecConfig: }
04-21 18:04:47.030 10916 10954 D CCodecConfig: no c2 equivalents for durationUs
04-21 18:04:47.030 10916 10954 D CCodecConfig: no c2 equivalents for csd-1
04-21 18:04:47.030 10916 10954 D CCodecConfig: no c2 equivalents for track-id
04-21 18:04:47.030 10916 10954 D CCodecConfig: no c2 equivalents for channel-mask
04-21 18:04:47.032 10916 10954 D CCodecConfig: c2 config diff is c2::u32 raw.sample-rate.value = 44100
04-21 18:04:47.035 10916 10954 W Codec2Client: query – param skipped: index = 1107298332.
04-21 18:04:47.035 10916 10954 D CCodec : setup formats input: AMessage(what = 0x00000000) = {
04-21 18:04:47.035 10916 10954 D CCodec : int32_t channel-count = 1
04-21 18:04:47.035 10916 10954 D CCodec : int32_t max-input-size = 32768
04-21 18:04:47.035 10916 10954 D CCodec : string mime = “audio/vorbis”
04-21 18:04:47.035 10916 10954 D CCodec : int32_t sample-rate = 44100
04-21 18:04:47.035 10916 10954 D CCodec : } and output: AMessage(what = 0x00000000) = {
04-21 18:04:47.035 10916 10954 D CCodec : int32_t channel-count = 1
04-21 18:04:47.035 10916 10954 D CCodec : string mime = “audio/raw”
04-21 18:04:47.035 10916 10954 D CCodec : int32_t sample-rate = 44100
04-21 18:04:47.035 10916 10954 D CCodec : int32_t channel-mask = 1
04-21 18:04:47.035 10916 10954 D CCodec : }
04-21 18:04:47.040 10916 10954 W Codec2Client: query – param skipped: index = 1342179345.
04-21 18:04:47.041 10916 10954 W Codec2Client: query – param skipped: index = 2415921170.
04-21 18:04:47.045 10916 10954 D CCodecBufferChannel: [c2.android.vorbis.decoder#582] Created input block pool with allocatorID 16 => poolID 17 - OK (0)
04-21 18:04:47.054 10916 10954 I CCodecBufferChannel: [c2.android.vorbis.decoder#582] Created output block pool with allocatorID 16 => poolID 400 - OK
04-21 18:04:47.054 10916 10954 D CCodecBufferChannel: [c2.android.vorbis.decoder#582] Configured output block pool ids 400 => OK
04-21 18:04:47.055 10916 10954 E ion : ioctl c0044901 failed with code -1: Invalid argument
04-21 18:04:47.145 10979 10979 W com.termux: type=1400 audit(0.0:3440): avc: granted { execute } for name=“login” dev=“mmcblk0p62” ino=533503 scontext=u:r:untrusted_app_27:s0:c227,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c227,c256,c512,c768 tclass=file app=com.termux
04-21 18:04:47.145 10979 10979 W com.termux: type=1400 audit(0.0:3441): avc: granted { execute_no_trans } for path=“/data/data/com.termux/files/usr/bin/login” dev=“mmcblk0p62” ino=533503 scontext=u:r:untrusted_app_27:s0:c227,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c227,c256,c512,c768 tclass=file app=com.termux
04-21 18:04:47.152 10979 10979 W com.termux: type=1400 audit(0.0:3442): avc: granted { execute } for name=“dash” dev=“mmcblk0p62” ino=533453 scontext=u:r:untrusted_app_27:s0:c227,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c227,c256,c512,c768 tclass=file app=com.termux
04-21 18:04:47.225 10979 10979 W login : type=1400 audit(0.0:3444): avc: granted { execute } for path=“/data/data/com.termux/files/usr/bin/dash” dev=“mmcblk0p62” ino=533453 scontext=u:r:untrusted_app_27:s0:c227,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c227,c256,c512,c768 tclass=file app=com.termux
04-21 18:04:47.272 10916 10916 I Choreographer: Skipped 57 frames! The application may be doing too much work on its main thread.
04-21 18:04:47.380 10916 10941 I OpenGLRenderer: Davey! duration=1061ms; Flags=0, IntendedVsync=175748132477243, Vsync=175749082477205, OldestInputEvent=9223372036854775807, NewestInputEvent=0, HandleInputStart=175749090037297, AnimationStart=175749090165213, PerformTraversalsStart=175749090345838, DrawStart=175749142220739, SyncQueued=175749175092461, SyncStart=175749179244285, IssueDrawCommandsStart=175749179679337, SwapBuffers=175749189565848, FrameCompleted=175749197679651, DequeueBufferDuration=538000, QueueBufferDuration=1315000,
04-21 18:04:47.445 10992 10992 W login : type=1400 audit(0.0:3446): avc: granted { execute } for name=“coreutils” dev=“mmcblk0p62” ino=533317 scontext=u:r:untrusted_app_27:s0:c227,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c227,c256,c512,c768 tclass=file app=com.termux
04-21 18:04:53.615 11163 11163 W bash : type=1400 audit(0.0:3480): avc: granted { execute } for name=“logcat” dev=“mmcblk0p62” ino=533502 scontext=u:r:untrusted_app_27:s0:c227,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c227,c256,c512,c768 tclass=file app=com.termux
04-21 18:04:53.629 11163 11163 W bash : type=1400 audit(0.0:3481): avc: granted { execute } for name=“logcat” dev=“mmcblk0p62” ino=533502 scontext=u:r:untrusted_app_27:s0:c227,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c227,c256,c512,c768 tclass=file app=com.termux
04-21 18:04:53.629 11163 11163 W bash : type=1400 audit(0.0:3482): avc: granted { execute_no_trans } for path=“/data/data/com.termux/files/usr/bin/logcat” dev=“mmcblk0p62” ino=533502 scontext=u:r:untrusted_app_27:s0:c227,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c227,c256,c512,c768 tclass=file app=com.termux
04-21 18:04:53.629 11163 11163 W bash : type=1400 audit(0.0:3483): avc: granted { execute } for name=“dash” dev=“mmcblk0p62” ino=533453 scontext=u:r:untrusted_app_27:s0:c227,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c227,c256,c512,c768 tclass=file app=com.termux
04-21 18:04:53.632 11163 11163 W logcat : type=1400 audit(0.0:3484): avc: granted { execute } for path=“/data/data/com.termux/files/usr/bin/dash” dev=“mmcblk0p62” ino=533453 scontext=u:r:untrusted_app_27:s0:c227,c256,c512,c768 tcontext=u:object_r:app_data_file:s0:c227,c256,c512,c768 tclass=file app=com.termux
04-21 18:06:32.734 10916 10916 W ActivityThread: handleWindowVisibility: no activity for token android.os.BinderProxy@cfaf51e
04-21 18:06:32.814 10916 11581 D CCodec : allocate(c2.android.vorbis.decoder)
04-21 18:06:32.820 10916 11581 I CCodec : Created component [c2.android.vorbis.decoder]
04-21 18:06:32.821 10916 11581 D CCodecConfig: read media type: audio/vorbis
04-21 18:06:32.827 10916 11581 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.max-count.values
04-21 18:06:32.827 10916 11581 D ReflectedParamUpdater: extent() != 1 for single value type: output.subscribed-indices.values
04-21 18:06:32.828 10916 11581 D ReflectedParamUpdater: extent() != 1 for single value type: input.buffers.allocator-ids.values
04-21 18:06:32.829 10916 11581 D ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.allocator-ids.values
04-21 18:06:32.829 10916 11581 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.allocator-ids.values
04-21 18:06:32.830 10916 11581 D ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.pool-ids.values
04-21 18:06:32.831 10916 11581 D ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.pool-ids.values
04-21 18:06:32.834 10916 11581 I CCodecConfig: query failed after returning 7 values (BAD_INDEX)
04-21 18:06:32.834 10916 11581 D CCodecConfig: c2 config diff is Dict {
04-21 18:06:32.834 10916 11581 D CCodecConfig: c2::u32 coded.bitrate.value = 64000
04-21 18:06:32.834 10916 11581 D CCodecConfig: c2::u32 input.buffers.max-size.value = 32768
04-21 18:06:32.834 10916 11581 D CCodecConfig: c2::u32 input.delay.value = 0
04-21 18:06:32.834 10916 11581 D CCodecConfig: string input.media-type.value = “audio/vorbis”
04-21 18:06:32.834 10916 11581 D CCodecConfig: string output.media-type.value = “audio/raw”
04-21 18:06:32.834 10916 11581 D CCodecConfig: c2::u32 raw.channel-count.value = 1
04-21 18:06:32.834 10916 11581 D CCodecConfig: c2::u32 raw.sample-rate.value = 48000
04-21 18:06:32.834 10916 11581 D CCodecConfig: }
04-21 18:06:32.835 10916 11581 D CCodecConfig: no c2 equivalents for durationUs
04-21 18:06:32.835 10916 11581 D CCodecConfig: no c2 equivalents for csd-1
04-21 18:06:32.835 10916 11581 D CCodecConfig: no c2 equivalents for track-id
04-21 18:06:32.835 10916 11581 D CCodecConfig: no c2 equivalents for channel-mask
04-21 18:06:32.837 10916 11581 D CCodecConfig: c2 config diff is c2::u32 raw.sample-rate.value = 44100
04-21 18:06:32.837 10916 11581 W Codec2Client: query – param skipped: index = 1107298332.
04-21 18:06:32.838 10916 11581 D CCodec : setup formats input: AMessage(what = 0x00000000) = {
04-21 18:06:32.838 10916 11581 D CCodec : int32_t channel-count = 1
04-21 18:06:32.838 10916 11581 D CCodec : int32_t max-input-size = 32768
04-21 18:06:32.838 10916 11581 D CCodec : string mime = “audio/vorbis”
04-21 18:06:32.838 10916 11581 D CCodec : int32_t sample-rate = 44100
04-21 18:06:32.838 10916 11581 D CCodec : } and output: AMessage(what = 0x00000000) = {
04-21 18:06:32.838 10916 11581 D CCodec : int32_t channel-count = 1
04-21 18:06:32.838 10916 11581 D CCodec : string mime = “audio/raw”
04-21 18:06:32.838 10916 11581 D CCodec : int32_t sample-rate = 44100
04-21 18:06:32.838 10916 11581 D CCodec : int32_t channel-mask = 1
04-21 18:06:32.838 10916 11581 D CCodec : }
04-21 18:06:32.839 10916 11581 W Codec2Client: query – param skipped: index = 1342179345.
04-21 18:06:32.840 10916 11581 W Codec2Client: query – param skipped: index = 2415921170.
04-21 18:06:32.842 10916 11581 D CCodecBufferChannel: [c2.android.vorbis.decoder#356] Created input block pool with allocatorID 16 => poolID 18 - OK (0)
04-21 18:06:32.844 10916 10967 D BufferPoolAccessor: bufferpool2 0x77b5c5f820 : 0(0 size) total buffers - 0(0 size) used buffers - 1/9 (recycle/alloc) - 8/24 (fetch/transfer)
04-21 18:06:32.844 10916 10967 D BufferPoolAccessor: Destruction - bufferpool2 0x77b5c5f820 cached: 0/0M, 0/0% in use; allocs: 9, 11% recycled; transfers: 24, 67% unfetced
04-21 18:06:32.844 10916 11581 I CCodecBufferChannel: [c2.android.vorbis.decoder#356] Created output block pool with allocatorID 16 => poolID 401 - OK
04-21 18:06:32.845 10916 11581 D CCodecBufferChannel: [c2.android.vorbis.decoder#356] Configured output block pool ids 401 => OK
04-21 18:07:02.268 10916 10967 D BufferPoolAccessor: bufferpool2 0x77ae60e820 : 0(0 size) total buffers - 0(0 size) used buffers - 3/9 (recycle/alloc) - 6/24 (fetch/transfer)
04-21 18:07:02.269 10916 10967 D BufferPoolAccessor: Destruction - bufferpool2 0x77ae60e820 cached: 0/0M, 0/0% in use; allocs: 9, 33% recycled; transfers: 24, 75% unfetced
read: unexpected EOF!

In case I’ve made something wrong, please tell me how to improve it.

Jayky · April 22, 2021, 6:07pm

Today I`ve tried it another time. I used

logcat ActivityManager:I AusweisApp2:D *:S

to get only the necessary information. Unfortunately, there was none. I have done the same steps as before and the log just ends with

read: unexpected EOF!

without anything else. This time I`ve done a screenshots:

Again, after a while AusweisApp2 crashed. I haven’t done a restart to see what will happen. The whole OS was really slow. I couldn`t start the settings to force a shutdown of the app nether to deactivate NFC. About one minute later it worked normal, but within the next hour my device had a shutdown that I have not noticed. So it looks to me that the whole process has initiated an instability of the whole system. Now, around 4 hours later it works fine.

Is it possible that there is a deeper issue with NFC functionality in /e/OS?

Jayky · April 22, 2021, 6:08pm

By the way, the NFC check was fine beforehand:

nickwhit · May 25, 2021, 5:33am

I have the the same problem with “no extended lenght” .

And I have no Idea what this means. My Phone (Samsung Galaxy S7 Model 930F) is in the list of supported phones. But obviously it doesnt work with the Eelo OS.

Does anybody know where I can find the “extended length” setting, maybe it can just be switched on?

Jayky · May 26, 2021, 7:02pm

Just a short update:

No changes after doing the update to /e/OS 0.16-20210422111920.
@ /e/ Support Team: is the NFC functionality something that is on your agenda?

sircali · August 27, 2021, 7:11pm

Same problem here with the S8.
Extend length communication error with AusweisApp2

Katswiri · May 16, 2023, 11:36am

Hi all,
I have a Murena One and sometimes need to autheticate myself with the AusweisApp2. The connection worked but wasn’t stable. Multiple disconnections. Support advised me to install the NFC Reader App from F-Droid. I don’t know if it keeps the NFC connection alive, anyway it worked. No more problems.
Since I wasn’t sure how to use the NFC Reader, whether it is active in the background or not, I just opened the app and then the AusweisApp2.

lando3 · September 9, 2023, 3:48pm

Didn’t work for me unfortunately.