Received-SPF: pass (google.com: domain of linux-bluetooth-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) client-ip=23.128.96.18;
MIME-Version: 1.0
References: <CAO9gXyRLOk75wdTWO_cAu1e=w82H1b_fWB=hLpHcJYcv2MHQDg@mail.gmail.com>
 <BYAPR14MB288775932E88E9B5CDF3A653E6F80@BYAPR14MB2887.namprd14.prod.outlook.com>
In-Reply-To: <BYAPR14MB288775932E88E9B5CDF3A653E6F80@BYAPR14MB2887.namprd14.prod.outlook.com>
From:   C K <choongbeom@gmail.com>
Date:   Thu, 17 Dec 2020 17:51:43 +0900
Message-ID: <CAO9gXyS_9aB+ka4xp=QRA0fQ-utVfakTsnXtBvfwhzDio+UE6Q@mail.gmail.com>
Subject: =?UTF-8?Q?Re=3A_BlueZ_=E2=80=9CPin_or_Key_missing=E2=80=9D_occurred_even_tho?=
        =?UTF-8?Q?ugh_it_has_already_been_paired?=
To:     Jamie Mccrae <Jamie.Mccrae@lairdconnect.com>
Cc:     "linux-bluetooth@vger.kernel.org" <linux-bluetooth@vger.kernel.org>
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable
Precedence: bulk

Hi Jamie,
I'm very sorry for late reply. I was busy with other urgent works.

Could you check this log?
Why is "Removing temporary device..." happening?


=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D first connection and pairing =
with my android test app
: connect -> bonded -> disconnect from app
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
Dec 17 07:35:38  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_ref() 0xfd1000: ref=3D1
Dec 17 07:35:38  bluetoothd[368]:
../bluez-5.50/src/agent.c:register_agent() agent :1.49
Dec 17 07:35:38  bluetoothd[368]:
../bluez-5.50/src/agent.c:unregister_agent() agent :1.49
Dec 17 07:35:38  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_disconnect() Agent :1.49 disconnected
Dec 17 07:35:38  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_destroy() agent :1.49
Dec 17 07:35:38  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_unref() 0xfd1000: ref=3D0
Dec 17 07:35:38  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_ref() 0xfd1000: ref=3D1
Dec 17 07:35:38  bluetoothd[368]:
../bluez-5.50/src/agent.c:register_agent() agent :1.49
Dec 17 07:35:38  bluetoothd[368]:
../bluez-5.50/src/agent.c:add_default_agent() Default agent set to
:1.49 /org/bluez/agent
Dec 17 07:35:46  bluetoothd[368]:
../bluez-5.50/src/adapter.c:connected_callback() hci0 device
5C:CB:99:7F:77:02 connected eir_len 0
Dec 17 07:35:47  bluetoothd[368]:
../bluez-5.50/src/adapter.c:user_passkey_notify_callback() hci0
5C:CB:99:7F:77:02
Dec 17 07:35:47  bluetoothd[368]:
../bluez-5.50/src/adapter.c:user_passkey_notify_callback() passkey
859060 entered 0
Dec 17 07:35:47  bluetoothd[368]:
../bluez-5.50/src/device.c:new_auth() Requesting agent authentication
for 5C:CB:99:7F:77:02
Dec 17 07:35:47  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_ref() 0xfd1000: ref=3D2
Dec 17 07:35:56  bluetoothd[368]:
../bluez-5.50/src/adapter.c:new_irk_callback() hci0 new IRK for
5C:CB:99:7F:77:02 RPA 00:00:00:00:00:00
Dec 17 07:35:56  bluetoothd[368]:
../bluez-5.50/src/adapter.c:new_csrk_callback() hci0 new CSRK for
5C:CB:99:7F:77:02 type 3
Dec 17 07:35:56  bluetoothd[368]:
../bluez-5.50/src/adapter.c:new_csrk_callback() hci0 new CSRK for
5C:CB:99:7F:77:02 type 2
Dec 17 07:35:56  bluetoothd[368]:
../bluez-5.50/src/adapter.c:new_long_term_key_callback() hci0 new LTK
for 5C:CB:99:7F:77:02 type 1 enc_size 16
Dec 17 07:35:56  bluetoothd[368]: ../bluez-5.50/src/device.c:device_set_bon=
ded()
Dec 17 07:35:56  bluetoothd[368]:
../bluez-5.50/src/device.c:device_bonding_complete() bonding (nil)
status 0x00
Dec 17 07:35:56  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_unref() 0xfd1000: ref=3D1
Dec 17 07:35:56  bluetoothd[368]: ../bluez-5.50/src/adapter.c:resume_discov=
ery()
Dec 17 07:35:56  bluetoothd[368]:
../bluez-5.50/src/adapter.c:new_long_term_key_callback() hci0 new LTK
for 5C:CB:99:7F:77:02 type 1 enc_size 16
Dec 17 07:35:56  bluetoothd[368]: ../bluez-5.50/src/device.c:device_set_bon=
ded()
Dec 17 07:35:56  bluetoothd[368]:
../bluez-5.50/src/device.c:device_bonding_complete() bonding (nil)
status 0x00
Dec 17 07:35:56  bluetoothd[368]: ../bluez-5.50/src/adapter.c:resume_discov=
ery()
Dec 17 07:36:15  bluetoothd[368]:
../bluez-5.50/src/adapter.c:dev_disconnected() Device
5C:CB:99:7F:77:02 disconnected, reason 3
Dec 17 07:36:15  bluetoothd[368]:
../bluez-5.50/src/adapter.c:adapter_remove_connection()
Dec 17 07:36:15  bluetoothd[368]:
../bluez-5.50/plugins/policy.c:disconnect_cb() reason 3
Dec 17 07:36:15  bluetoothd[368]:
../bluez-5.50/src/adapter.c:bonding_attempt_complete() hci0 bdaddr
5C:CB:99:7F:77:02 type 1 status 0xe
Dec 17 07:36:15  bluetoothd[368]:
../bluez-5.50/src/device.c:device_bonding_complete() bonding (nil)
status 0x0e
Dec 17 07:36:15  bluetoothd[368]:
../bluez-5.50/src/device.c:device_bonding_failed() status 14
Dec 17 07:36:15  bluetoothd[368]: ../bluez-5.50/src/adapter.c:resume_discov=
ery()
Dec 17 07:36:36  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_disconnect() Agent :1.49 disconnected
Dec 17 07:36:36  bluetoothd[368]:
../bluez-5.50/src/agent.c:remove_default_agent() Default agent cleared
Dec 17 07:36:36  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_destroy() agent :1.49
Dec 17 07:36:36  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_unref() 0xfd1000: ref=3D0
Dec 17 07:36:37  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_ref() 0xfd2808: ref=3D1
Dec 17 07:36:37  bluetoothd[368]:
../bluez-5.50/src/agent.c:register_agent() agent :1.51
Dec 17 07:36:37  bluetoothd[368]:
../bluez-5.50/src/agent.c:unregister_agent() agent :1.51
Dec 17 07:36:37  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_disconnect() Agent :1.51 disconnected
Dec 17 07:36:37  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_destroy() agent :1.51
Dec 17 07:36:37  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_unref() 0xfd2808: ref=3D0

=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D second connection : this device unp=
aired unintentionally
from the app system as soon as connected
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
Dec 17 07:36:37  bluetoothd[368]:
../bluez-5.50/src/agent.c:agent_ref() 0xfd2808: ref=3D1
Dec 17 07:36:37  bluetoothd[368]:
../bluez-5.50/src/agent.c:register_agent() agent :1.51
Dec 17 07:36:37  bluetoothd[368]:
../bluez-5.50/src/agent.c:add_default_agent() Default agent set to
:1.51 /org/bluez/agent
Dec 17 07:36:42  bluetoothd[368]:
../bluez-5.50/src/adapter.c:connected_callback() hci0 device
4D:EE:4F:F1:6F:FD connected eir_len 0
Dec 17 07:36:42  bluetoothd[368]:
../bluez-5.50/src/device.c:device_create() dst 4D:EE:4F:F1:6F:FD
Dec 17 07:36:42  bluetoothd[368]:
../bluez-5.50/src/device.c:device_new() address 4D:EE:4F:F1:6F:FD
Dec 17 07:36:42  bluetoothd[368]:
../bluez-5.50/src/device.c:device_new() Creating device
/org/bluez/hci0/dev_4D_EE_4F_F1_6F_FD
Dec 17 07:36:43  bluetoothd[368]:
../bluez-5.50/src/adapter.c:dev_disconnected() Device
4D:EE:4F:F1:6F:FD disconnected, reason 3
Dec 17 07:36:43  bluetoothd[368]:
../bluez-5.50/src/adapter.c:adapter_remove_connection()
Dec 17 07:36:43  bluetoothd[368]:
../bluez-5.50/src/adapter.c:adapter_remove_connection() Removing
temporary device /org/bluez/hci0/dev_4D_EE_4F_F1_6F_FD
Dec 17 07:36:43  bluetoothd[368]:
../bluez-5.50/src/device.c:device_remove() Removing device
/org/bluez/hci0/dev_4D_EE_4F_F1_6F_FD
Dec 17 07:36:43  bluetoothd[368]:
../bluez-5.50/src/device.c:btd_device_unref() Freeing device
/org/bluez/hci0/dev_4D_EE_4F_F1_6F_FD
Dec 17 07:36:43  bluetoothd[368]:
../bluez-5.50/src/device.c:device_free() 0xff3058
Dec 17 07:36:43  bluetoothd[368]:
../bluez-5.50/plugins/policy.c:disconnect_cb() reason 3
Dec 17 07:36:43  bluetoothd[368]:
../bluez-5.50/src/adapter.c:bonding_attempt_complete() hci0 bdaddr
4D:EE:4F:F1:6F:FD type 2 status 0xe
Dec 17 07:36:43  bluetoothd[368]: ../bluez-5.50/src/adapter.c:resume_discov=
ery()


Thanks,
Calvin

2020=EB=85=84 11=EC=9B=94 27=EC=9D=BC (=EA=B8=88) =EC=98=A4=ED=9B=84 5:43, =
Jamie Mccrae <Jamie.Mccrae@lairdconnect.com>=EB=8B=98=EC=9D=B4 =EC=9E=91=EC=
=84=B1:
>
> Hi Calvin,
> What type of address is it? If the device has a random resolvable address=
 then this means once the device has paired and exchanged IRK that regardle=
ss of what random resolvable address the device uses, the other device will=
 always know what the device's true address is and will use the correct enc=
ryption keys and details. If the device has a different random non-resolvab=
le address or random static address which changes then you cannot match the=
se against a pairing.
> Thanks,
> Jamie
>
> -----Original Message-----
> From: C K <choongbeom@gmail.com>
> Sent: 27 November 2020 06:46
> To: linux-bluetooth@vger.kernel.org
> Subject: BlueZ =E2=80=9CPin or Key missing=E2=80=9D occurred even though =
it has already been paired
>
> EXTERNAL EMAIL: Be careful with attachments and links.
>
> Hello,
> I have an issue with my bluez device.
> I explained it on stackover flow.
> Help me about this please.
>
> https://stackoverflow.com/questions/65001891/bluez-pin-or-key-missing-occ=
urred-even-though-it-has-already-been-paired
>
>
> Thanks,
> Calvin
> THIS MESSAGE, ANY ATTACHMENT(S), AND THE INFORMATION CONTAINED HEREIN MAY=
 BE PROPRIETARY TO LAIRD CONNECTIVITY, INC. AND/OR ANOTHER PARTY, AND MAY F=
URTHER BE INTENDED TO BE KEPT CONFIDENTIAL. IF YOU ARE NOT THE INTENDED REC=
IPIENT, PLEASE DELETE THE EMAIL AND ANY ATTACHMENTS, AND IMMEDIATELY NOTIFY=
 THE SENDER BY RETURN EMAIL. THIS MESSAGE AND ITS CONTENTS ARE THE PROPERTY=
 OF LAIRD CONNECTIVITY, INC. AND MAY NOT BE REPRODUCED OR USED WITHOUT THE =
EXPRESS WRITTEN CONSENT OF LAIRD CONNECTIVITY, INC.