Hi
I have a strange problem with dectmon. I would like to monitor the conversations between a Siemens AS150 and it's base station. I started the cluster in monitoring mode with the same emc and fpn as the original base station in pp mode:
dect-cluster-add --name cluster0 --emc $EMC --fpn $FPN --mode pp --monitor dect-cell-add --name cell0 --cluster cluster0 dect-transceiver-bind --transceiver trx0 --cell cell0
Now, when I launch dectmon, I get these messages:
# ./dectmon -n yes netlink: cluster0: mode PP ARI: class A: EMC: 0ff6 FPN: 0deb7 LCE: set default pmid e94bd LCE: registered protocol 0 (Link Control) LCE: registered protocol 3 (Call Control) LCE: registered protocol 4 (Call Independant Supplementary Services) LCE: registered protocol 6 (ConnectionLess Message Service) LCE: registered protocol 5 (Mobility Management)
netlink: message group: 4 netlink: FPC: full_slot,page_repetition,basic_a_field_setup,in_min_delay netlink: HLC: adpcm_g721_voice,gap_pap_basic_speech,standard_authentication,location_registration unknown unknown
netlink: message group: 4
Should't there be more output? I am sure that at least some location registration or authentication messages are exchanged here.
I am running 2.6.36, but I did not update to the latest version in the git tree yet.
Am 08.11.2010 18:27, schrieb Erik Tews:
Hi
I have a strange problem with dectmon. I would like to monitor the conversations between a Siemens AS150 and it's base station. I started the cluster in monitoring mode with the same emc and fpn as the original base station in pp mode:
dect-cluster-add --name cluster0 --emc $EMC --fpn $FPN --mode pp --monitor dect-cell-add --name cell0 --cluster cluster0 dect-transceiver-bind --transceiver trx0 --cell cell0
Now, when I launch dectmon, I get these messages:
# ./dectmon -n yes netlink: cluster0: mode PP ARI: class A: EMC: 0ff6 FPN: 0deb7 LCE: set default pmid e94bd LCE: registered protocol 0 (Link Control) LCE: registered protocol 3 (Call Control) LCE: registered protocol 4 (Call Independant Supplementary Services) LCE: registered protocol 6 (ConnectionLess Message Service) LCE: registered protocol 5 (Mobility Management)
netlink: message group: 4 netlink: FPC: full_slot,page_repetition,basic_a_field_setup,in_min_delay netlink: HLC: adpcm_g721_voice,gap_pap_basic_speech,standard_authentication,location_registration unknown unknown
netlink: message group: 4
Should't there be more output? I am sure that at least some location registration or authentication messages are exchanged here.
I am running 2.6.36, but I did not update to the latest version in the git tree yet.
This usually happens when the monitor is not properly locked to the station. If you enable debugging in the kernel, does it show DBC messages?
Am 08.11.2010 18:27, schrieb Erik Tews:
Hi
I have a strange problem with dectmon. I would like to monitor the conversations between a Siemens AS150 and it's base station. I started the cluster in monitoring mode with the same emc and fpn as the original base station in pp mode:
dect-cluster-add --name cluster0 --emc $EMC --fpn $FPN --mode pp --monitor
Actually, this seems to be the problem, the syntax is "--flags monitor".
dect-cell-add --name cell0 --cluster cluster0 dect-transceiver-bind --transceiver trx0 --cell cell0
I now switched that to:
dect-cluster-add --name cluster0 --emc $EMC --fpn $FPN --mode pp dect-cell-add --name cell0 --cluster cluster0 --flags monitor dect-transceiver-bind --transceiver trx0 --cell cell0
But I still have the same problem.
Do I need a newer kernel than commit 75a0d091dc8074ef940932cf6027fcdf59277070 to run the kernel in monitoring-mode?
Am Dienstag, den 09.11.2010, 11:16 +0100 schrieb Patrick McHardy:
Am 08.11.2010 18:27, schrieb Erik Tews:
Hi
I have a strange problem with dectmon. I would like to monitor the conversations between a Siemens AS150 and it's base station. I started the cluster in monitoring mode with the same emc and fpn as the original base station in pp mode:
dect-cluster-add --name cluster0 --emc $EMC --fpn $FPN --mode pp --monitor
Actually, this seems to be the problem, the syntax is "--flags monitor".
dect-cell-add --name cell0 --cluster cluster0 dect-transceiver-bind --transceiver trx0 --cell cell0
On 14.11.2010 01:55, Erik Tews wrote:
I now switched that to:
dect-cluster-add --name cluster0 --emc $EMC --fpn $FPN --mode pp dect-cell-add --name cell0 --cluster cluster0 --flags monitor dect-transceiver-bind --transceiver trx0 --cell cell0
But I still have the same problem.
Do I need a newer kernel than commit 75a0d091dc8074ef940932cf6027fcdf59277070 to run the kernel in monitoring-mode?
No, that one should be fine. If you're still seeing
netlink: message group: 4
without FPC and HLC following, that means that the PP lost lock with the FP. If you enable debugging for mac_csf.c, you should see the reason in the logs.
On 14.11.2010 14:04, Patrick McHardy wrote:
On 14.11.2010 01:55, Erik Tews wrote:
I now switched that to:
dect-cluster-add --name cluster0 --emc $EMC --fpn $FPN --mode pp dect-cell-add --name cell0 --cluster cluster0 --flags monitor dect-transceiver-bind --transceiver trx0 --cell cell0
But I still have the same problem.
Do I need a newer kernel than commit 75a0d091dc8074ef940932cf6027fcdf59277070 to run the kernel in monitoring-mode?
No, that one should be fine. If you're still seeing
netlink: message group: 4
without FPC and HLC following, that means that the PP lost lock with the FP. If you enable debugging for mac_csf.c, you should see the reason in the logs.
BTW:
netlink: message group: 4 netlink: FPC: full_slot,page_repetition,basic_a_field_setup,in_min_delay netlink: HLC: adpcm_g721_voice,gap_pap_basic_speech,standard_authentication,location_registration
It seems your FP doesn't support ciphering, so its possible that it doesn't broadcast the multi-frame number, which my stack expects. It shouldn't have locked to the FP in that case though.
Perhaps the FP broadcasts the MFN at a lesser frequency than defined in the standard - if the stack doesn't receive the MFN at least every 8 multiframes (T216), it unlocks from the FP.
Am Sonntag, den 14.11.2010, 14:10 +0100 schrieb Patrick McHardy:
BTW:
netlink: message group: 4 netlink: FPC:
full_slot,page_repetition,basic_a_field_setup,in_min_delay
netlink: HLC:
adpcm_g721_voice,gap_pap_basic_speech,standard_authentication,location_registration
It seems your FP doesn't support ciphering, so its possible that it doesn't broadcast the multi-frame number, which my stack expects. It shouldn't have locked to the FP in that case though.
Perhaps the FP broadcasts the MFN at a lesser frequency than defined in the standard - if the stack doesn't receive the MFN at least every 8 multiframes (T216), it unlocks from the FP.
Well, I tried the base station of my AS150 phone, where I am not sure if it supports ciphering, I guess it doesn't support ciphering.
However, I tried my Fritzbox 7270 too, which definitely supports ciphering. I will try again with my Fritzbox.
Am Sonntag, den 14.11.2010, 14:15 +0100 schrieb Erik Tews:
Am Sonntag, den 14.11.2010, 14:10 +0100 schrieb Patrick McHardy:
BTW:
netlink: message group: 4 netlink: FPC:
full_slot,page_repetition,basic_a_field_setup,in_min_delay
netlink: HLC:
adpcm_g721_voice,gap_pap_basic_speech,standard_authentication,location_registration
It seems your FP doesn't support ciphering, so its possible that it doesn't broadcast the multi-frame number, which my stack expects. It shouldn't have locked to the FP in that case though.
Perhaps the FP broadcasts the MFN at a lesser frequency than defined in the standard - if the stack doesn't receive the MFN at least every 8 multiframes (T216), it unlocks from the FP.
Well, I tried the base station of my AS150 phone, where I am not sure if it supports ciphering, I guess it doesn't support ciphering.
However, I tried my Fritzbox 7270 too, which definitely supports ciphering. I will try again with my Fritzbox.
OK, here is the kern.log for my Fritzbox. I am running the PCI card on a 32 bit Linux system. It takes minutes, until my computer in monitor-mode has found the Fritzbox. During the discovery, it finds a lot of other FPs. I am running that test in a very populated area with most probably a lot of other phones around my house.
What happens after my box has found the Fritzbox and got a lock on it is, that it seems to be able to hold the lock for a few seconds, but then runs into a timeout. Then it needs some seconds, but more like 10-40 to get the lock again.
Nov 15 14:57:49 pc2 kernel: [603017.486809] cell0: RX 218329.02.00: timer cd139df8: 218329.2.0 Nov 15 14:57:49 pc2 kernel: [603017.486817] cell0: RX 218329.02.00: timer cd139df8: schedule for 218329.3.0 Nov 15 14:57:49 pc2 kernel: [603017.489319] cell0: RX 218329.01.23: timer cd139dd8: 218329.1.23 Nov 15 14:57:49 pc2 kernel: [603017.489326] cell0: RX 218329.01.23: timer cd139dd8: schedule for 218329.2.23 Nov 15 14:57:49 pc2 kernel: [603017.494315] DBC slot 6 carrier 7: RSSI: selection: 0 now: 246 Nov 15 14:57:49 pc2 kernel: [603017.496818] cell0: RX 218329.03.00: timer cd139df8: 218329.3.0 Nov 15 14:57:49 pc2 kernel: [603017.496827] cell0: RX 218329.03.00: timer cd139df8: schedule for 218329.4.0 Nov 15 14:57:49 pc2 kernel: [603017.499531] RX 218329.02.20: trx0: Q1: 0 Q2: 1 A/B: 40 carrier: 6 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 14:57:49 pc2 kernel: [603017.499541] cell0: RX 218329.02.23: timer cd139dd8: 218329.2.23 Nov 15 14:57:49 pc2 kernel: [603017.499546] cell0: RX 218329.02.23: timer cd139dd8: schedule for 218329.3.23 Nov 15 14:57:49 pc2 kernel: [603017.502040] RX 218329.03.04: trx0: Q1: 1 Q2: 1 A/B: 24 carrier: 8 A-CRC: 0 X-CRC: 0 DBC slot 6 carrier 7: RSSI: selection: 0 now: 246 Nov 15 14:57:49 pc2 kernel: [603017.506808] cell0: RX 218329.04.00: timer cd139df8: 218329.4.0 Nov 15 14:57:49 pc2 kernel: [603017.506816] cell0: RX 218329.04.00: timer cd139df8: schedule for 218329.5.0 Nov 15 14:57:49 pc2 kernel: [603017.509317] cell0: RX 218329.03.23: timer cd139dd8: 218329.3.23 Nov 15 14:57:49 pc2 kernel: [603017.509324] cell0: RX 218329.03.23: timer cd139dd8: schedule for 218329.4.23 Nov 15 14:57:49 pc2 kernel: [603017.514539] DBC slot 6 carrier 7: RSSI: selection: 0 now: 246 Nov 15 14:57:49 pc2 kernel: [603017.514554] RX 218329.04.10: trx0: Q1: 1 Q2: 0 A/B: ae carrier: 9 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 14:57:49 pc2 kernel: [603017.516815] cell0: RX 218329.05.00: timer cd139df8: 218329.5.0 Nov 15 14:57:49 pc2 kernel: [603017.516824] cell0: RX 218329.05.00: timer cd139df8: schedule for 218329.6.0 Nov 15 14:57:49 pc2 kernel: [603017.519301] cell0: RX 218329.04.23: timer cd139dd8: 218329.4.23 Nov 15 14:57:49 pc2 kernel: [603017.519306] cell0: RX 218329.04.23: timer cd139dd8: schedule for 218329.5.23 Nov 15 14:57:49 pc2 kernel: [603017.524308] DBC slot 6 carrier 7: RSSI: selection: 0 now: 246 Nov 15 14:57:49 pc2 kernel: [603017.526805] cell0: RX 218329.06.00: timer cd139df8: 218329.6.0 Nov 15 14:57:49 pc2 kernel: [603017.526813] cell0: RX 218329.06.00: timer cd139df8: schedule for 218329.7.0 Nov 15 14:57:49 pc2 kernel: [603017.529314] cell0: RX 218329.05.23: timer cd139dd8: 218329.5.23 Nov 15 14:57:49 pc2 kernel: [603017.529321] cell0: RX 218329.05.23: timer cd139dd8: schedule for 218329.6.23 Nov 15 14:57:49 pc2 kernel: [603017.534535] DBC slot 6 carrier 7: RSSI: selection: 0 now: 246 Nov 15 14:57:49 pc2 kernel: [603017.534547] RX 218329.06.08: trx0: Q1: 0 Q2: 0 A/B: 80 carrier: 1 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 14:57:49 pc2 kernel: [603017.536811] cell0: RX 218329.07.00: timer cd139df8: 218329.7.0 Nov 15 14:57:49 pc2 kernel: [603017.536821] cell0: RX 218329.07.00: timer cd139df8: schedule for 218329.8.0 Nov 15 14:57:49 pc2 kernel: [603017.539299] cell0: RX 218329.06.23: timer cd139dd8: 218329.6.23 Nov 15 14:57:49 pc2 kernel: [603017.539305] cell0: RX 218329.06.23: timer cd139dd8: schedule for 218329.7.23 Nov 15 14:57:49 pc2 kernel: [603017.544302] DBC slot 6 carrier 7: RSSI: selection: 0 now: 238 Nov 15 14:57:49 pc2 kernel: [603017.546802] cell0: RX 218329.08.00: timer cd139df8: 218329.8.0 Nov 15 14:57:49 pc2 kernel: [603017.546810] cell0: RX 218329.08.00: timer cd139df8: schedule for 218329.9.0 Nov 15 14:57:49 pc2 kernel: [603017.549311] cell0: RX 218329.07.23: timer cd139dd8: 218329.7.23 Nov 15 14:57:49 pc2 kernel: [603017.549318] cell0: RX 218329.07.23: timer cd139dd8: schedule for 218329.8.23 Nov 15 14:57:49 pc2 kernel: [603017.554527] DBC slot 6 carrier 7: RSSI: selection: 0 now: 238 Nov 15 14:57:49 pc2 kernel: [603017.554541] RX 218329.08.10: trx0: Q1: 1 Q2: 0 A/B: 6e carrier: 3 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 14:57:49 pc2 kernel: [603017.557038] cell0: RX 218329.09.00: timer cd139df8: 218329.9.0 Nov 15 14:57:49 pc2 kernel: [603017.557048] cell0: RX 218329.09.00: timer cd139df8: schedule for 218329.10.0 Nov 15 14:57:49 pc2 kernel: [603017.557057] RX 218329.08.14: trx0: Q1: 0 Q2: 0 A/B: a0 carrier: 2 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 14:57:49 pc2 kernel: [603017.559297] cell0: RX 218329.08.23: timer cd139dd8: 218329.8.23 Nov 15 14:57:49 pc2 kernel: [603017.559302] cell0: RX 218329.08.23: timer cd139dd8: schedule for 218329.9.23 Nov 15 14:57:49 pc2 kernel: [603017.564299] DBC slot 6 carrier 7: RSSI: selection: 0 now: 238 Nov 15 14:57:49 pc2 kernel: [603017.566800] cell0: RX 218329.10.00: timer cd139df8: 218329.10.0 Nov 15 14:57:49 pc2 kernel: [603017.566808] cell0: RX 218329.10.00: timer cd139df8: schedule for 218329.11.0 Nov 15 14:57:49 pc2 kernel: [603017.569307] cell0: RX 218329.09.23: timer cd139dd8: 218329.9.23 Nov 15 14:57:49 pc2 kernel: [603017.569314] cell0: RX 218329.09.23: timer cd139dd8: schedule for 218329.10.23 Nov 15 14:57:49 pc2 kernel: [603017.574303] DBC slot 6 carrier 7: RSSI: selection: 0 now: 238 Nov 15 14:57:49 pc2 kernel: [603017.576808] cell0: RX 218329.11.00: timer cd139df8: 218329.11.0 Nov 15 14:57:49 pc2 kernel: [603017.576816] cell0: RX 218329.11.00: timer cd139df8: schedule for 218329.12.0 Nov 15 14:57:49 pc2 kernel: [603017.579294] cell0: RX 218329.10.23: timer cd139dd8: 218329.10.23 Nov 15 14:57:49 pc2 kernel: [603017.579299] cell0: RX 218329.10.23: timer cd139dd8: schedule for 218329.11.23 Nov 15 14:57:49 pc2 kernel: [603017.584300] DBC slot 6 carrier 7: RSSI: selection: 0 now: 242 Nov 15 14:57:49 pc2 kernel: [603017.586796] cell0: RX 218329.12.00: timer cd139df8: 218329.12.0 Nov 15 14:57:49 pc2 kernel: [603017.586804] cell0: RX 218329.12.00: timer cd139df8: schedule for 218329.13.0 Nov 15 14:57:49 pc2 kernel: [603017.589306] cell0: RX 218329.11.23: timer cd139dd8: 218329.11.23 Nov 15 14:57:49 pc2 kernel: [603017.589313] cell0: RX 218329.11.23: timer cd139dd8: schedule for 218329.12.23 Nov 15 14:57:49 pc2 kernel: [603017.594301] DBC slot 6 carrier 7: RSSI: selection: 0 now: 238 Nov 15 14:57:49 pc2 kernel: [603017.596805] cell0: RX 218329.13.00: timer cd139df8: 218329.13.0 Nov 15 14:57:49 pc2 kernel: [603017.596814] cell0: RX 218329.13.00: timer cd139df8: schedule for 218329.14.0 Nov 15 14:57:49 pc2 kernel: [603017.599517] RX 218329.12.18: trx0: Q1: 0 Q2: 1 A/B: ee carrier: 6 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Unknown MAC control 6000000000000000
### Any idea where that Unknown MAC control comes from?
Nov 15 14:57:49 pc2 kernel: [603017.599530] cell0: RX 218329.12.23: timer cd139dd8: 218329.12.23 Nov 15 14:57:49 pc2 kernel: [603017.599535] cell0: RX 218329.12.23: timer cd139dd8: schedule for 218329.13.23 Nov 15 14:57:49 pc2 kernel: [603017.604294] DBC slot 6 carrier 7: RSSI: selection: 0 now: 238 Nov 15 14:57:49 pc2 kernel: [603017.606795] cell0: RX 218329.14.00: timer cd139df8: 218329.14.0 Nov 15 14:57:49 pc2 kernel: [603017.606803] cell0: RX 218329.14.00: timer cd139df8: schedule for 218329.15.0 Nov 15 14:57:49 pc2 kernel: [603017.609536] RX 218329.13.22: trx0: Q1: 1 Q2: 0 A/B: 20 carrier: 7 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 14:57:49 pc2 kernel: [603017.609545] cell0: RX 218329.13.23: timer cd139dd8: 218329.13.23 Nov 15 14:57:49 pc2 kernel: [603017.609551] cell0: RX 218329.13.23: timer cd139dd8: schedule for 218329.14.23 Nov 15 14:57:49 pc2 kernel: [603017.614301] DBC slot 6 carrier 7: RSSI: selection: 0 now: 234 Nov 15 14:57:49 pc2 kernel: [603017.616802] cell0: RX 218329.15.00: timer cd139df8: 218329.15.0 Nov 15 14:57:49 pc2 kernel: [603017.616811] cell0: RX 218329.15.00: timer cd139df8: schedule for 218330.0.0 Nov 15 14:57:49 pc2 kernel: [603017.619512] RX 218329.14.22: trx0: Q1: 0 Q2: 0 A/B: ca carrier: 8 A-CRC: 0 X-CRC: 0 Unknown MAC control 3000000000000000 Nov 15 14:57:49 pc2 kernel: [603017.619522] cell0: RX 218329.14.23: timer cd139dd8: 218329.14.23 Nov 15 14:57:49 pc2 kernel: [603017.619527] cell0: RX 218329.14.23: timer cd139dd8: schedule for 218329.15.23 Nov 15 14:57:49 pc2 kernel: [603017.624291] DBC slot 6 carrier 7: RSSI: selection: 0 now: 234 Nov 15 14:57:49 pc2 kernel: [603017.626792] cell0: RX 218330.00.00: timer cd139df8: 218330.0.0 Nov 15 14:57:49 pc2 kernel: [603017.626800] cell0: RX 218330.00.00: timer cd139df8: schedule for 218330.1.0 Nov 15 14:57:49 pc2 kernel: [603017.629300] cell0: RX 218329.15.23: timer cd139dd8: 218329.15.23 Nov 15 14:57:49 pc2 kernel: [603017.629307] cell0: RX 218329.15.23: timer cd139dd8: schedule for 218330.0.23 Nov 15 14:57:49 pc2 kernel: [603017.629312] timeout, unlock, a: 159 nt: 101 mfn: 9
### From here on, it seems to have lost the lock of the FP
Nov 15 14:57:49 pc2 kernel: [603017.629322] cl cd2e0000: MAC_INFO-ind: rpn: 0 Nov 15 14:57:50 pc2 kernel: [603018.283036] connectionless: identities information: e: 1 class: 0 emc: 0080 fpn: 07405 rpn: 7 Nov 15 14:57:50 pc2 kernel: [603018.527295] unknown tail a0 Nov 15 14:57:50 pc2 kernel: [603018.568814] identities information: e: 0 class: 0 emc: 11f0 fpn: 1611c rpn: 0 Nov 15 14:57:51 pc2 kernel: [603018.731582] extended rf carrier information: rfcars 50000000 band 26 num 1 Nov 15 14:57:51 pc2 kernel: [603018.954793] connectionless: identities information: e: 0 class: 0 emc: 08a7 fpn: 040b2 rpn: 0 Nov 15 14:57:51 pc2 kernel: [603018.974890] encctrl: cmd: 1 fmid: 0a3a pmid: 00d34 Nov 15 14:57:51 pc2 kernel: [603019.179211] identities information: e: 0 class: 0 emc: 006b fpn: 0ff38 rpn: 0 Nov 15 14:57:51 pc2 kernel: [603019.223252] unknown system information type 7000000000000000 Nov 15 14:57:52 pc2 kernel: [603019.998634] identities information: e: 0 class: 0 emc: 11f0 fpn: 1691c rpn: 0 Nov 15 14:57:52 pc2 kernel: [603020.384959] C_S tail sequence number 0 Nov 15 14:57:52 pc2 kernel: [603020.567434] identities information: e: 0 class: 0 emc: 0397 fpn: 141be rpn: 0 Nov 15 14:57:52 pc2 kernel: [603020.629240] identities information: e: 0 class: 1 emc: a362 fpn: 00010 rpn: 10 Nov 15 14:57:53 pc2 kernel: [603020.791895] identities information: e: 0 class: 0 emc: 07f6 fpn: 03463 rpn: 0 Nov 15 14:57:53 pc2 kernel: [603021.547044] connectionless: identities information: e: 0 class: 0 emc: d31a fpn: 1842c rpn: 6 Nov 15 14:57:54 pc2 kernel: [603021.994986] page: RFPI: ea9d8 blind full slots: a28 Nov 15 14:57:54 pc2 kernel: [603022.035430] identities information: e: 0 class: 0 emc: 0a43 fpn: 0c048 rpn: 0 Nov 15 14:57:54 pc2 kernel: [603022.157050] identities information: e: 0 class: 3 emc: f439 fpn: 0008b rpn: f7 Nov 15 14:57:54 pc2 kernel: [603022.197227] connectionless: identities information: e: 0 class: 0 emc: 0387 fpn: 14494 rpn: 0 Nov 15 14:57:55 pc2 kernel: [603022.831636] identities information: e: 0 class: 0 emc: 07f6 fpn: 13443 rpn: 0 Nov 15 14:57:56 pc2 kernel: [603023.851170] connectionless: identities information: e: 1 class: 3 emc: a183 fpn: 000a9 rpn: 8b Nov 15 14:57:56 pc2 kernel: [603024.054154] identities information: e: 0 class: 0 emc: 0804 fpn: 000a2 rpn: 0 Nov 15 14:57:56 pc2 kernel: [603024.074242] unknown tail a0 Nov 15 14:57:56 pc2 kernel: [603024.278570] static system information: nr: 0 sn: 6 cn: 9 pscn: 6 Nov 15 14:57:56 pc2 kernel: [603024.461427] unknown cctrl command: 900000000000000 Nov 15 14:57:57 pc2 kernel: [603025.054607] C_S tail sequence number 1
Here is another log on the same machine, but this time, it doesn't say a word about unknown MAC control:
Nov 15 15:03:07 pc2 kernel: [603335.317365] cell0: RX 220315.13.00: timer cd139df8: schedule for 220315.14.0 Nov 15 15:03:07 pc2 kernel: [603335.319844] cell0: RX 220315.12.23: timer cd139dd8: 220315.12.23 Nov 15 15:03:07 pc2 kernel: [603335.319850] cell0: RX 220315.12.23: timer cd139dd8: schedule for 220315.13.23 Nov 15 15:03:07 pc2 kernel: [603335.324850] DBC slot 6 carrier 7: RSSI: selection: 0 now: 234 Nov 15 15:03:07 pc2 kernel: [603335.327341] cell0: RX 220315.14.00: timer cd139df8: 220315.14.0 Nov 15 15:03:07 pc2 kernel: [603335.327349] cell0: RX 220315.14.00: timer cd139df8: schedule for 220315.15.0 Nov 15 15:03:07 pc2 kernel: [603335.329855] cell0: RX 220315.13.23: timer cd139dd8: 220315.13.23 Nov 15 15:03:07 pc2 kernel: [603335.329862] cell0: RX 220315.13.23: timer cd139dd8: schedule for 220315.14.23 Nov 15 15:03:07 pc2 kernel: [603335.334847] DBC slot 6 carrier 7: RSSI: selection: 0 now: 234 Nov 15 15:03:07 pc2 kernel: [603335.337355] cell0: RX 220315.15.00: timer cd139df8: 220315.15.0 Nov 15 15:03:07 pc2 kernel: [603335.337364] cell0: RX 220315.15.00: timer cd139df8: schedule for 220316.0.0 Nov 15 15:03:07 pc2 kernel: [603335.340083] RX 220315.14.18: trx0: Q1: 0 Q2: 0 A/B: 80 carrier: 4 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 15:03:07 pc2 kernel: [603335.340093] cell0: RX 220315.14.23: timer cd139dd8: 220315.14.23 Nov 15 15:03:07 pc2 kernel: [603335.340099] cell0: RX 220315.14.23: timer cd139dd8: schedule for 220315.15.23 Nov 15 15:03:07 pc2 kernel: [603335.344846] DBC slot 6 carrier 7: RSSI: selection: 0 now: 234 Nov 15 15:03:07 pc2 kernel: [603335.347340] cell0: RX 220316.00.00: timer cd139df8: 220316.0.0 Nov 15 15:03:07 pc2 kernel: [603335.347348] cell0: RX 220316.00.00: timer cd139df8: schedule for 220316.1.0 Nov 15 15:03:07 pc2 kernel: [603335.349853] cell0: RX 220315.15.23: timer cd139dd8: 220315.15.23 Nov 15 15:03:07 pc2 kernel: [603335.349860] cell0: RX 220315.15.23: timer cd139dd8: schedule for 220316.0.23 Nov 15 15:03:07 pc2 kernel: [603335.349865] timeout, unlock, a: 199 nt: 171 mfn: 9 Nov 15 15:03:07 pc2 kernel: [603335.349875] cl cd2e0000: MAC_INFO-ind: rpn: 0 Nov 15 15:03:08 pc2 kernel: [603335.758892] unknown MAC page info 0 Nov 15 15:03:08 pc2 kernel: [603336.351786] identities information: e: 0 class: 0 emc: 07f6 fpn: 12072 rpn: 0 Nov 15 15:03:09 pc2 kernel: [603336.761731] identities information: e: 0 class: 0 emc: 07f4 fpn: 13462 rpn: 0 Nov 15 15:03:09 pc2 kernel: [603337.008980] C_S tail sequence number 0 Nov 15 15:03:10 pc2 kernel: [603338.090210] C_S tail sequence number 0 Nov 15 15:03:10 pc2 kernel: [603338.274403] static system information: nr: 0 sn: 5 cn: 2 pscn: 3 Nov 15 15:03:10 pc2 kernel: [603338.601499] identities information: e: 0 class: 0 emc: 06e4 fpn: 02042 rpn: 0 Nov 15 15:03:10 pc2 kernel: [603338.643032] connectionless: identities information: e: 1 class: 2 emc: dd7a fpn: 0005f rpn: df Nov 15 15:03:11 pc2 kernel: [603338.785825] C_S tail sequence number 1 Nov 15 15:03:11 pc2 kernel: [603339.280452] C_S tail sequence number 0 Nov 15 15:03:12 pc2 kernel: [603339.848379] identities information: e: 0 class: 0 emc: 11f0 fpn: 1691c rpn: 0 Nov 15 15:03:12 pc2 kernel: [603340.093837] C_S tail sequence number 1 Nov 15 15:03:12 pc2 kernel: [603340.114035] Unknown MAC control d000000000000000 Nov 15 15:03:12 pc2 kernel: [603340.215766] identities information: e: 0 class: 4 emc: 0410 fpn: 007b1 rpn: d8 Nov 15 15:03:13 pc2 kernel: [603340.746906] unknown tail a0 Nov 15 15:03:13 pc2 kernel: [603340.827436] identities information: e: 0 class: 1 emc: 0397 fpn: 00020 rpn: 64 Nov 15 15:03:13 pc2 kernel: [603340.888397] C_S tail sequence number 1 Nov 15 15:03:13 pc2 kernel: [603340.970535] full/long page: extend: 1 length: 7000000000000000 Nov 15 15:03:13 pc2 kernel: [603341.174531] unknown tail a0 Nov 15 15:03:13 pc2 kernel: [603341.235558] unknown tail a0 Nov 15 15:03:13 pc2 kernel: [603341.318620] connectionless: identities information: e: 0 class: 4 emc: ce3a fpn: 00020 rpn: 10 Nov 15 15:03:13 pc2 kernel: [603341.420344] extended rf carrier information: rfcars e0000000 band 22 num 1
On 15.11.2010 15:06, Erik Tews wrote:
Am Sonntag, den 14.11.2010, 14:15 +0100 schrieb Erik Tews:
Am Sonntag, den 14.11.2010, 14:10 +0100 schrieb Patrick McHardy:
BTW:
netlink: message group: 4 netlink: FPC:
full_slot,page_repetition,basic_a_field_setup,in_min_delay
netlink: HLC:
adpcm_g721_voice,gap_pap_basic_speech,standard_authentication,location_registration
It seems your FP doesn't support ciphering, so its possible that it doesn't broadcast the multi-frame number, which my stack expects. It shouldn't have locked to the FP in that case though.
Perhaps the FP broadcasts the MFN at a lesser frequency than defined in the standard - if the stack doesn't receive the MFN at least every 8 multiframes (T216), it unlocks from the FP.
Well, I tried the base station of my AS150 phone, where I am not sure if it supports ciphering, I guess it doesn't support ciphering.
However, I tried my Fritzbox 7270 too, which definitely supports ciphering. I will try again with my Fritzbox.
OK, here is the kern.log for my Fritzbox. I am running the PCI card on a 32 bit Linux system. It takes minutes, until my computer in monitor-mode has found the Fritzbox. During the discovery, it finds a lot of other FPs. I am running that test in a very populated area with most probably a lot of other phones around my house.
What happens after my box has found the Fritzbox and got a lock on it is, that it seems to be able to hold the lock for a few seconds, but then runs into a timeout. Then it needs some seconds, but more like 10-40 to get the lock again.
Nov 15 14:57:49 pc2 kernel: [603017.486809] cell0: RX 218329.02.00: timer cd139df8: 218329.2.0 Nov 15 14:57:49 pc2 kernel: [603017.486817] cell0: RX 218329.02.00: timer cd139df8: schedule for 218329.3.0 Nov 15 14:57:49 pc2 kernel: [603017.489319] cell0: RX 218329.01.23: timer cd139dd8: 218329.1.23 Nov 15 14:57:49 pc2 kernel: [603017.489326] cell0: RX 218329.01.23: timer cd139dd8: schedule for 218329.2.23 Nov 15 14:57:49 pc2 kernel: [603017.494315] DBC slot 6 carrier 7: RSSI: selection: 0 now: 246 Nov 15 14:57:49 pc2 kernel: [603017.496818] cell0: RX 218329.03.00: timer cd139df8: 218329.3.0 Nov 15 14:57:49 pc2 kernel: [603017.496827] cell0: RX 218329.03.00: timer cd139df8: schedule for 218329.4.0 Nov 15 14:57:49 pc2 kernel: [603017.499531] RX 218329.02.20: trx0: Q1: 0 Q2: 1 A/B: 40 carrier: 6 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 14:57:49 pc2 kernel: [603017.499541] cell0: RX 218329.02.23: timer cd139dd8: 218329.2.23 Nov 15 14:57:49 pc2 kernel: [603017.499546] cell0: RX 218329.02.23: timer cd139dd8: schedule for 218329.3.23 Nov 15 14:57:49 pc2 kernel: [603017.502040] RX 218329.03.04: trx0: Q1: 1 Q2: 1 A/B: 24 carrier: 8 A-CRC: 0 X-CRC: 0 DBC slot 6 carrier 7: RSSI: selection: 0 now: 246 Nov 15 14:57:49 pc2 kernel: [603017.506808] cell0: RX 218329.04.00: timer cd139df8: 218329.4.0 Nov 15 14:57:49 pc2 kernel: [603017.506816] cell0: RX 218329.04.00: timer cd139df8: schedule for 218329.5.0 Nov 15 14:57:49 pc2 kernel: [603017.509317] cell0: RX 218329.03.23: timer cd139dd8: 218329.3.23 Nov 15 14:57:49 pc2 kernel: [603017.509324] cell0: RX 218329.03.23: timer cd139dd8: schedule for 218329.4.23 Nov 15 14:57:49 pc2 kernel: [603017.514539] DBC slot 6 carrier 7: RSSI: selection: 0 now: 246 Nov 15 14:57:49 pc2 kernel: [603017.514554] RX 218329.04.10: trx0: Q1: 1 Q2: 0 A/B: ae carrier: 9 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 14:57:49 pc2 kernel: [603017.516815] cell0: RX 218329.05.00: timer cd139df8: 218329.5.0 Nov 15 14:57:49 pc2 kernel: [603017.516824] cell0: RX 218329.05.00: timer cd139df8: schedule for 218329.6.0 Nov 15 14:57:49 pc2 kernel: [603017.519301] cell0: RX 218329.04.23: timer cd139dd8: 218329.4.23 Nov 15 14:57:49 pc2 kernel: [603017.519306] cell0: RX 218329.04.23: timer cd139dd8: schedule for 218329.5.23 Nov 15 14:57:49 pc2 kernel: [603017.524308] DBC slot 6 carrier 7: RSSI: selection: 0 now: 246 Nov 15 14:57:49 pc2 kernel: [603017.526805] cell0: RX 218329.06.00: timer cd139df8: 218329.6.0 Nov 15 14:57:49 pc2 kernel: [603017.526813] cell0: RX 218329.06.00: timer cd139df8: schedule for 218329.7.0 Nov 15 14:57:49 pc2 kernel: [603017.529314] cell0: RX 218329.05.23: timer cd139dd8: 218329.5.23 Nov 15 14:57:49 pc2 kernel: [603017.529321] cell0: RX 218329.05.23: timer cd139dd8: schedule for 218329.6.23 Nov 15 14:57:49 pc2 kernel: [603017.534535] DBC slot 6 carrier 7: RSSI: selection: 0 now: 246 Nov 15 14:57:49 pc2 kernel: [603017.534547] RX 218329.06.08: trx0: Q1: 0 Q2: 0 A/B: 80 carrier: 1 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 14:57:49 pc2 kernel: [603017.536811] cell0: RX 218329.07.00: timer cd139df8: 218329.7.0 Nov 15 14:57:49 pc2 kernel: [603017.536821] cell0: RX 218329.07.00: timer cd139df8: schedule for 218329.8.0 Nov 15 14:57:49 pc2 kernel: [603017.539299] cell0: RX 218329.06.23: timer cd139dd8: 218329.6.23 Nov 15 14:57:49 pc2 kernel: [603017.539305] cell0: RX 218329.06.23: timer cd139dd8: schedule for 218329.7.23 Nov 15 14:57:49 pc2 kernel: [603017.544302] DBC slot 6 carrier 7: RSSI: selection: 0 now: 238 Nov 15 14:57:49 pc2 kernel: [603017.546802] cell0: RX 218329.08.00: timer cd139df8: 218329.8.0 Nov 15 14:57:49 pc2 kernel: [603017.546810] cell0: RX 218329.08.00: timer cd139df8: schedule for 218329.9.0 Nov 15 14:57:49 pc2 kernel: [603017.549311] cell0: RX 218329.07.23: timer cd139dd8: 218329.7.23 Nov 15 14:57:49 pc2 kernel: [603017.549318] cell0: RX 218329.07.23: timer cd139dd8: schedule for 218329.8.23 Nov 15 14:57:49 pc2 kernel: [603017.554527] DBC slot 6 carrier 7: RSSI: selection: 0 now: 238 Nov 15 14:57:49 pc2 kernel: [603017.554541] RX 218329.08.10: trx0: Q1: 1 Q2: 0 A/B: 6e carrier: 3 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 14:57:49 pc2 kernel: [603017.557038] cell0: RX 218329.09.00: timer cd139df8: 218329.9.0 Nov 15 14:57:49 pc2 kernel: [603017.557048] cell0: RX 218329.09.00: timer cd139df8: schedule for 218329.10.0 Nov 15 14:57:49 pc2 kernel: [603017.557057] RX 218329.08.14: trx0: Q1: 0 Q2: 0 A/B: a0 carrier: 2 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 14:57:49 pc2 kernel: [603017.559297] cell0: RX 218329.08.23: timer cd139dd8: 218329.8.23 Nov 15 14:57:49 pc2 kernel: [603017.559302] cell0: RX 218329.08.23: timer cd139dd8: schedule for 218329.9.23 Nov 15 14:57:49 pc2 kernel: [603017.564299] DBC slot 6 carrier 7: RSSI: selection: 0 now: 238 Nov 15 14:57:49 pc2 kernel: [603017.566800] cell0: RX 218329.10.00: timer cd139df8: 218329.10.0 Nov 15 14:57:49 pc2 kernel: [603017.566808] cell0: RX 218329.10.00: timer cd139df8: schedule for 218329.11.0 Nov 15 14:57:49 pc2 kernel: [603017.569307] cell0: RX 218329.09.23: timer cd139dd8: 218329.9.23 Nov 15 14:57:49 pc2 kernel: [603017.569314] cell0: RX 218329.09.23: timer cd139dd8: schedule for 218329.10.23 Nov 15 14:57:49 pc2 kernel: [603017.574303] DBC slot 6 carrier 7: RSSI: selection: 0 now: 238 Nov 15 14:57:49 pc2 kernel: [603017.576808] cell0: RX 218329.11.00: timer cd139df8: 218329.11.0 Nov 15 14:57:49 pc2 kernel: [603017.576816] cell0: RX 218329.11.00: timer cd139df8: schedule for 218329.12.0 Nov 15 14:57:49 pc2 kernel: [603017.579294] cell0: RX 218329.10.23: timer cd139dd8: 218329.10.23 Nov 15 14:57:49 pc2 kernel: [603017.579299] cell0: RX 218329.10.23: timer cd139dd8: schedule for 218329.11.23 Nov 15 14:57:49 pc2 kernel: [603017.584300] DBC slot 6 carrier 7: RSSI: selection: 0 now: 242 Nov 15 14:57:49 pc2 kernel: [603017.586796] cell0: RX 218329.12.00: timer cd139df8: 218329.12.0 Nov 15 14:57:49 pc2 kernel: [603017.586804] cell0: RX 218329.12.00: timer cd139df8: schedule for 218329.13.0 Nov 15 14:57:49 pc2 kernel: [603017.589306] cell0: RX 218329.11.23: timer cd139dd8: 218329.11.23 Nov 15 14:57:49 pc2 kernel: [603017.589313] cell0: RX 218329.11.23: timer cd139dd8: schedule for 218329.12.23 Nov 15 14:57:49 pc2 kernel: [603017.594301] DBC slot 6 carrier 7: RSSI: selection: 0 now: 238 Nov 15 14:57:49 pc2 kernel: [603017.596805] cell0: RX 218329.13.00: timer cd139df8: 218329.13.0 Nov 15 14:57:49 pc2 kernel: [603017.596814] cell0: RX 218329.13.00: timer cd139df8: schedule for 218329.14.0 Nov 15 14:57:49 pc2 kernel: [603017.599517] RX 218329.12.18: trx0: Q1: 0 Q2: 1 A/B: ee carrier: 6 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Unknown MAC control 6000000000000000
### Any idea where that Unknown MAC control comes from?
0x6 is "Tail for use with the first transmission of a B-field "bearer request" message". This is simply not handled by my code. Often these are just reception errors or frames received from different FPs/PPs.
Nov 15 14:57:49 pc2 kernel: [603017.599530] cell0: RX 218329.12.23: timer cd139dd8: 218329.12.23 Nov 15 14:57:49 pc2 kernel: [603017.599535] cell0: RX 218329.12.23: timer cd139dd8: schedule for 218329.13.23 Nov 15 14:57:49 pc2 kernel: [603017.604294] DBC slot 6 carrier 7: RSSI: selection: 0 now: 238 Nov 15 14:57:49 pc2 kernel: [603017.606795] cell0: RX 218329.14.00: timer cd139df8: 218329.14.0 Nov 15 14:57:49 pc2 kernel: [603017.606803] cell0: RX 218329.14.00: timer cd139df8: schedule for 218329.15.0 Nov 15 14:57:49 pc2 kernel: [603017.609536] RX 218329.13.22: trx0: Q1: 1 Q2: 0 A/B: 20 carrier: 7 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 14:57:49 pc2 kernel: [603017.609545] cell0: RX 218329.13.23: timer cd139dd8: 218329.13.23 Nov 15 14:57:49 pc2 kernel: [603017.609551] cell0: RX 218329.13.23: timer cd139dd8: schedule for 218329.14.23 Nov 15 14:57:49 pc2 kernel: [603017.614301] DBC slot 6 carrier 7: RSSI: selection: 0 now: 234 Nov 15 14:57:49 pc2 kernel: [603017.616802] cell0: RX 218329.15.00: timer cd139df8: 218329.15.0 Nov 15 14:57:49 pc2 kernel: [603017.616811] cell0: RX 218329.15.00: timer cd139df8: schedule for 218330.0.0 Nov 15 14:57:49 pc2 kernel: [603017.619512] RX 218329.14.22: trx0: Q1: 0 Q2: 0 A/B: ca carrier: 8 A-CRC: 0 X-CRC: 0 Unknown MAC control 3000000000000000 Nov 15 14:57:49 pc2 kernel: [603017.619522] cell0: RX 218329.14.23: timer cd139dd8: 218329.14.23 Nov 15 14:57:49 pc2 kernel: [603017.619527] cell0: RX 218329.14.23: timer cd139dd8: schedule for 218329.15.23 Nov 15 14:57:49 pc2 kernel: [603017.624291] DBC slot 6 carrier 7: RSSI: selection: 0 now: 234 Nov 15 14:57:49 pc2 kernel: [603017.626792] cell0: RX 218330.00.00: timer cd139df8: 218330.0.0 Nov 15 14:57:49 pc2 kernel: [603017.626800] cell0: RX 218330.00.00: timer cd139df8: schedule for 218330.1.0 Nov 15 14:57:49 pc2 kernel: [603017.629300] cell0: RX 218329.15.23: timer cd139dd8: 218329.15.23 Nov 15 14:57:49 pc2 kernel: [603017.629307] cell0: RX 218329.15.23: timer cd139dd8: schedule for 218330.0.23 Nov 15 14:57:49 pc2 kernel: [603017.629312] timeout, unlock, a: 159 nt: 101 mfn: 9
### From here on, it seems to have lost the lock of the FP
Indeed, the multi-frame resync timer has timed out (mfn:9, max is 8). It seems it didn't receive a valid tail message over the entire previous period, judging by the log. I'd guess that the transceiver has drifted off too much. You should be able to see that by watching the output of dect-transceiver-list for the slot in question.
Does locking to that PF work if you don't use monitor mode?
Nov 15 14:57:49 pc2 kernel: [603017.629322] cl cd2e0000: MAC_INFO-ind: rpn: 0 Nov 15 14:57:50 pc2 kernel: [603018.283036] connectionless: identities information: e: 1 class: 0 emc: 0080 fpn: 07405 rpn: 7 Nov 15 14:57:50 pc2 kernel: [603018.527295] unknown tail a0 Nov 15 14:57:50 pc2 kernel: [603018.568814] identities information: e: 0 class: 0 emc: 11f0 fpn: 1611c rpn: 0 Nov 15 14:57:51 pc2 kernel: [603018.731582] extended rf carrier information: rfcars 50000000 band 26 num 1 Nov 15 14:57:51 pc2 kernel: [603018.954793] connectionless: identities information: e: 0 class: 0 emc: 08a7 fpn: 040b2 rpn: 0 Nov 15 14:57:51 pc2 kernel: [603018.974890] encctrl: cmd: 1 fmid: 0a3a pmid: 00d34 Nov 15 14:57:51 pc2 kernel: [603019.179211] identities information: e: 0 class: 0 emc: 006b fpn: 0ff38 rpn: 0 Nov 15 14:57:51 pc2 kernel: [603019.223252] unknown system information type 7000000000000000 Nov 15 14:57:52 pc2 kernel: [603019.998634] identities information: e: 0 class: 0 emc: 11f0 fpn: 1691c rpn: 0 Nov 15 14:57:52 pc2 kernel: [603020.384959] C_S tail sequence number 0 Nov 15 14:57:52 pc2 kernel: [603020.567434] identities information: e: 0 class: 0 emc: 0397 fpn: 141be rpn: 0 Nov 15 14:57:52 pc2 kernel: [603020.629240] identities information: e: 0 class: 1 emc: a362 fpn: 00010 rpn: 10 Nov 15 14:57:53 pc2 kernel: [603020.791895] identities information: e: 0 class: 0 emc: 07f6 fpn: 03463 rpn: 0 Nov 15 14:57:53 pc2 kernel: [603021.547044] connectionless: identities information: e: 0 class: 0 emc: d31a fpn: 1842c rpn: 6 Nov 15 14:57:54 pc2 kernel: [603021.994986] page: RFPI: ea9d8 blind full slots: a28 Nov 15 14:57:54 pc2 kernel: [603022.035430] identities information: e: 0 class: 0 emc: 0a43 fpn: 0c048 rpn: 0 Nov 15 14:57:54 pc2 kernel: [603022.157050] identities information: e: 0 class: 3 emc: f439 fpn: 0008b rpn: f7 Nov 15 14:57:54 pc2 kernel: [603022.197227] connectionless: identities information: e: 0 class: 0 emc: 0387 fpn: 14494 rpn: 0 Nov 15 14:57:55 pc2 kernel: [603022.831636] identities information: e: 0 class: 0 emc: 07f6 fpn: 13443 rpn: 0 Nov 15 14:57:56 pc2 kernel: [603023.851170] connectionless: identities information: e: 1 class: 3 emc: a183 fpn: 000a9 rpn: 8b Nov 15 14:57:56 pc2 kernel: [603024.054154] identities information: e: 0 class: 0 emc: 0804 fpn: 000a2 rpn: 0 Nov 15 14:57:56 pc2 kernel: [603024.074242] unknown tail a0 Nov 15 14:57:56 pc2 kernel: [603024.278570] static system information: nr: 0 sn: 6 cn: 9 pscn: 6 Nov 15 14:57:56 pc2 kernel: [603024.461427] unknown cctrl command: 900000000000000 Nov 15 14:57:57 pc2 kernel: [603025.054607] C_S tail sequence number 1
This is just random crap received while trying to regain lock.
Here is another log on the same machine, but this time, it doesn't say a word about unknown MAC control:
Nov 15 15:03:07 pc2 kernel: [603335.317365] cell0: RX 220315.13.00: timer cd139df8: schedule for 220315.14.0 Nov 15 15:03:07 pc2 kernel: [603335.319844] cell0: RX 220315.12.23: timer cd139dd8: 220315.12.23 Nov 15 15:03:07 pc2 kernel: [603335.319850] cell0: RX 220315.12.23: timer cd139dd8: schedule for 220315.13.23 Nov 15 15:03:07 pc2 kernel: [603335.324850] DBC slot 6 carrier 7: RSSI: selection: 0 now: 234 Nov 15 15:03:07 pc2 kernel: [603335.327341] cell0: RX 220315.14.00: timer cd139df8: 220315.14.0 Nov 15 15:03:07 pc2 kernel: [603335.327349] cell0: RX 220315.14.00: timer cd139df8: schedule for 220315.15.0 Nov 15 15:03:07 pc2 kernel: [603335.329855] cell0: RX 220315.13.23: timer cd139dd8: 220315.13.23 Nov 15 15:03:07 pc2 kernel: [603335.329862] cell0: RX 220315.13.23: timer cd139dd8: schedule for 220315.14.23 Nov 15 15:03:07 pc2 kernel: [603335.334847] DBC slot 6 carrier 7: RSSI: selection: 0 now: 234 Nov 15 15:03:07 pc2 kernel: [603335.337355] cell0: RX 220315.15.00: timer cd139df8: 220315.15.0 Nov 15 15:03:07 pc2 kernel: [603335.337364] cell0: RX 220315.15.00: timer cd139df8: schedule for 220316.0.0 Nov 15 15:03:07 pc2 kernel: [603335.340083] RX 220315.14.18: trx0: Q1: 0 Q2: 0 A/B: 80 carrier: 4 A-CRC: 0 X-CRC: 0 Z-CRC: 0 Nov 15 15:03:07 pc2 kernel: [603335.340093] cell0: RX 220315.14.23: timer cd139dd8: 220315.14.23 Nov 15 15:03:07 pc2 kernel: [603335.340099] cell0: RX 220315.14.23: timer cd139dd8: schedule for 220315.15.23 Nov 15 15:03:07 pc2 kernel: [603335.344846] DBC slot 6 carrier 7: RSSI: selection: 0 now: 234 Nov 15 15:03:07 pc2 kernel: [603335.347340] cell0: RX 220316.00.00: timer cd139df8: 220316.0.0 Nov 15 15:03:07 pc2 kernel: [603335.347348] cell0: RX 220316.00.00: timer cd139df8: schedule for 220316.1.0 Nov 15 15:03:07 pc2 kernel: [603335.349853] cell0: RX 220315.15.23: timer cd139dd8: 220315.15.23 Nov 15 15:03:07 pc2 kernel: [603335.349860] cell0: RX 220315.15.23: timer cd139dd8: schedule for 220316.0.23 Nov 15 15:03:07 pc2 kernel: [603335.349865] timeout, unlock, a: 199 nt: 171 mfn: 9
Same problem, multiframe resync has timed out, apparently no valid tails received.
Nov 15 15:03:07 pc2 kernel: [603335.349875] cl cd2e0000: MAC_INFO-ind: rpn: 0 Nov 15 15:03:08 pc2 kernel: [603335.758892] unknown MAC page info 0 Nov 15 15:03:08 pc2 kernel: [603336.351786] identities information: e: 0 class: 0 emc: 07f6 fpn: 12072 rpn: 0 Nov 15 15:03:09 pc2 kernel: [603336.761731] identities information: e: 0 class: 0 emc: 07f4 fpn: 13462 rpn: 0 Nov 15 15:03:09 pc2 kernel: [603337.008980] C_S tail sequence number 0 Nov 15 15:03:10 pc2 kernel: [603338.090210] C_S tail sequence number 0 Nov 15 15:03:10 pc2 kernel: [603338.274403] static system information: nr: 0 sn: 5 cn: 2 pscn: 3 Nov 15 15:03:10 pc2 kernel: [603338.601499] identities information: e: 0 class: 0 emc: 06e4 fpn: 02042 rpn: 0 Nov 15 15:03:10 pc2 kernel: [603338.643032] connectionless: identities information: e: 1 class: 2 emc: dd7a fpn: 0005f rpn: df Nov 15 15:03:11 pc2 kernel: [603338.785825] C_S tail sequence number 1 Nov 15 15:03:11 pc2 kernel: [603339.280452] C_S tail sequence number 0 Nov 15 15:03:12 pc2 kernel: [603339.848379] identities information: e: 0 class: 0 emc: 11f0 fpn: 1691c rpn: 0 Nov 15 15:03:12 pc2 kernel: [603340.093837] C_S tail sequence number 1 Nov 15 15:03:12 pc2 kernel: [603340.114035] Unknown MAC control d000000000000000 Nov 15 15:03:12 pc2 kernel: [603340.215766] identities information: e: 0 class: 4 emc: 0410 fpn: 007b1 rpn: d8 Nov 15 15:03:13 pc2 kernel: [603340.746906] unknown tail a0 Nov 15 15:03:13 pc2 kernel: [603340.827436] identities information: e: 0 class: 1 emc: 0397 fpn: 00020 rpn: 64 Nov 15 15:03:13 pc2 kernel: [603340.888397] C_S tail sequence number 1 Nov 15 15:03:13 pc2 kernel: [603340.970535] full/long page: extend: 1 length: 7000000000000000 Nov 15 15:03:13 pc2 kernel: [603341.174531] unknown tail a0 Nov 15 15:03:13 pc2 kernel: [603341.235558] unknown tail a0 Nov 15 15:03:13 pc2 kernel: [603341.318620] connectionless: identities information: e: 0 class: 4 emc: ce3a fpn: 00020 rpn: 10 Nov 15 15:03:13 pc2 kernel: [603341.420344] extended rf carrier information: rfcars e0000000 band 22 num 1
Am Montag, den 15.11.2010, 15:14 +0100 schrieb Patrick McHardy:
Indeed, the multi-frame resync timer has timed out (mfn:9, max is 8). It seems it didn't receive a valid tail message over the entire previous period, judging by the log. I'd guess that the transceiver has drifted off too much. You should be able to see that by watching the output of dect-transceiver-list for the slot in question.
Does locking to that PF work if you don't use monitor mode?
I will check that.
One strange thing, while scanning, I get a lot of messages with:
identities information: e: 0 class: 0 emc: ....
So my kernel finds a lot of PPs around it, but the Fritzbox is in the same room, only a few meters away, and it takes a minute or more until the Fritzbox pops up here.
As I understand the code at the moment, during the initial scan for the FP, the timing of the transmitter doesn't really matter. So we might assume that it is not a timing-problem which is responseable for this effect?
Am Montag, den 15.11.2010, 15:25 +0100 schrieb Erik Tews:
Am Montag, den 15.11.2010, 15:14 +0100 schrieb Patrick McHardy:
Indeed, the multi-frame resync timer has timed out (mfn:9, max is 8). It seems it didn't receive a valid tail message over the entire previous period, judging by the log. I'd guess that the transceiver has drifted off too much. You should be able to see that by watching the output of dect-transceiver-list for the slot in question.
Does locking to that PF work if you don't use monitor mode?
I will check that.
One strange thing, while scanning, I get a lot of messages with:
identities information: e: 0 class: 0 emc: ....
So my kernel finds a lot of PPs around it, but the Fritzbox is in the same room, only a few meters away, and it takes a minute or more until the Fritzbox pops up here.
As I understand the code at the moment, during the initial scan for the FP, the timing of the transmitter doesn't really matter. So we might assume that it is not a timing-problem which is responseable for this effect?
OK, so even without the monitor flag. my PC is now scanning for the FP since multiple minutes. So I assume that the problem is not related to the monitor flag.
On 15.11.2010 15:29, Erik Tews wrote:
Am Montag, den 15.11.2010, 15:25 +0100 schrieb Erik Tews:
Am Montag, den 15.11.2010, 15:14 +0100 schrieb Patrick McHardy:
Indeed, the multi-frame resync timer has timed out (mfn:9, max is 8). It seems it didn't receive a valid tail message over the entire previous period, judging by the log. I'd guess that the transceiver has drifted off too much. You should be able to see that by watching the output of dect-transceiver-list for the slot in question.
Does locking to that PF work if you don't use monitor mode?
I will check that.
One strange thing, while scanning, I get a lot of messages with:
identities information: e: 0 class: 0 emc: ....
So my kernel finds a lot of PPs around it, but the Fritzbox is in the same room, only a few meters away, and it takes a minute or more until the Fritzbox pops up here.
As I understand the code at the moment, during the initial scan for the FP, the timing of the transmitter doesn't really matter. So we might assume that it is not a timing-problem which is responseable for this effect?
OK, so even without the monitor flag. my PC is now scanning for the FP since multiple minutes. So I assume that the problem is not related to the monitor flag.
You could try to add to dect_mac_irc_tick, the DECT_TRANSCEIVER_UNLOCKED case, around the carrier increment:
if (net_random() > 0x7fffffff) { ... }
to have it stay on the same carrier half the time.
Am Montag, den 15.11.2010, 15:44 +0100 schrieb Patrick McHardy:
You could try to add to dect_mac_irc_tick, the DECT_TRANSCEIVER_UNLOCKED case, around the carrier increment:
if (net_random() > 0x7fffffff) { ... }
to have it stay on the same carrier half the time.
OK, that seems to improve the scanning results:
diff --git a/net/dect/mac_csf.c b/net/dect/mac_csf.c index a77f19f..9ec7a75 100644 --- a/net/dect/mac_csf.c +++ b/net/dect/mac_csf.c @@ -3656,9 +3656,11 @@ void dect_mac_irc_tick(struct dect_transceiver *trx)
switch (trx->state) { case DECT_TRANSCEIVER_UNLOCKED: - /* maintain scan until clock is running */ - irc->rx_scn = dect_next_carrier(0x3ff, irc->rx_scn); - dect_set_carrier(trx, DECT_SCAN_SLOT, irc->rx_scn); + if (net_random() > 0x7fffffff) { + /* maintain scan until clock is running */ + irc->rx_scn = dect_next_carrier(0x3ff, irc->rx_scn); + dect_set_carrier(trx, DECT_SCAN_SLOT, irc->rx_scn); + } break; case DECT_TRANSCEIVER_LOCK_PENDING: irc->si.ssi.pscn = dect_next_carrier(0x3ff, irc->si.ssi.pscn);
However, I don't get a lock just in PP mode, if I don't use the monitor flag:
[607158.216667] com_on_air_pci 0000:02:04.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18 [607158.216679] com_on_air_pci 0000:02:04.0: setting latency timer to 64 [607158.241899] com_on_air_pci 0000:02:04.0: Loading firmware ... [607158.788708] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607192.974449] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607219.881092] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607232.329542] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607263.615645] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607283.483168] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607287.032726] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607298.211337] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607307.220212] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607370.522330] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0
On 15.11.2010 16:14, Erik Tews wrote:
Am Montag, den 15.11.2010, 15:44 +0100 schrieb Patrick McHardy:
You could try to add to dect_mac_irc_tick, the DECT_TRANSCEIVER_UNLOCKED case, around the carrier increment:
if (net_random() > 0x7fffffff) { ... }
to have it stay on the same carrier half the time.
OK, that seems to improve the scanning results:
diff --git a/net/dect/mac_csf.c b/net/dect/mac_csf.c index a77f19f..9ec7a75 100644 --- a/net/dect/mac_csf.c +++ b/net/dect/mac_csf.c @@ -3656,9 +3656,11 @@ void dect_mac_irc_tick(struct dect_transceiver *trx)
switch (trx->state) { case DECT_TRANSCEIVER_UNLOCKED:
/* maintain scan until clock is running */irc->rx_scn = dect_next_carrier(0x3ff, irc->rx_scn);dect_set_carrier(trx, DECT_SCAN_SLOT, irc->rx_scn);
if (net_random() > 0x7fffffff) {/* maintain scan until clock is running */irc->rx_scn = dect_next_carrier(0x3ff, irc->rx_scn);dect_set_carrier(trx, DECT_SCAN_SLOT, irc->rx_scn);} break; case DECT_TRANSCEIVER_LOCK_PENDING: irc->si.ssi.pscn = dect_next_carrier(0x3ff, irc->si.ssi.pscn);However, I don't get a lock just in PP mode, if I don't use the monitor flag:
[607158.216667] com_on_air_pci 0000:02:04.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18 [607158.216679] com_on_air_pci 0000:02:04.0: setting latency timer to 64 [607158.241899] com_on_air_pci 0000:02:04.0: Loading firmware ... [607158.788708] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607192.974449] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607219.881092] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607232.329542] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607263.615645] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607283.483168] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607287.032726] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607298.211337] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607307.220212] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607370.522330] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0
The timings indicate that it only receives very few frames from the FP. Is it possible that it's operating in ECO-mode?
On 15.11.2010 16:19, Patrick McHardy wrote:
On 15.11.2010 16:14, Erik Tews wrote:
However, I don't get a lock just in PP mode, if I don't use the monitor flag:
[607158.216667] com_on_air_pci 0000:02:04.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18 [607158.216679] com_on_air_pci 0000:02:04.0: setting latency timer to 64 [607158.241899] com_on_air_pci 0000:02:04.0: Loading firmware ... [607158.788708] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607192.974449] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607219.881092] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607232.329542] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607263.615645] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607283.483168] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607287.032726] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607298.211337] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607307.220212] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607370.522330] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0
The timings indicate that it only receives very few frames from the FP. Is it possible that it's operating in ECO-mode?
One more thing you could try (I had the same problem occasionally, but it always magically disappeared at some point) is to change drivers/dect/coa/sc1442x.c and remove SC1442X_BC5_DO_FR from the BMC configuration. That sometimes helped in my case.
Am Montag, den 15.11.2010, 16:25 +0100 schrieb Patrick McHardy:
The timings indicate that it only receives very few frames from the FP. Is it possible that it's operating in ECO-mode?
One more thing you could try (I had the same problem occasionally, but it always magically disappeared at some point) is to change drivers/dect/coa/sc1442x.c and remove SC1442X_BC5_DO_FR from the BMC configuration. That sometimes helped in my case.
Sorry, again no luck:
diff --git a/drivers/dect/coa/sc1442x.c b/drivers/dect/coa/sc1442x.c index 9b15e81..c1cf9a8 100644 --- a/drivers/dect/coa/sc1442x.c +++ b/drivers/dect/coa/sc1442x.c @@ -911,7 +911,8 @@ static void sc1442x_write_bmc_config(const struct coa_device *dev, cfg |= 0x80; sc1442x_dwriteb(dev, off + 4, cfg);
- cfg = SC1442X_BC5_DO_FR; + // cfg = SC1442X_BC5_DO_FR; + cfg = 0; cfg |= tx ? SC1442X_BC5_TDO_DIGITAL : SC1442X_BC5_TDO_POWER_DOWN; sc1442x_dwriteb(dev, off + 5, cfg);
On 15.11.2010 16:46, Erik Tews wrote:
Am Montag, den 15.11.2010, 16:25 +0100 schrieb Patrick McHardy:
The timings indicate that it only receives very few frames from the FP. Is it possible that it's operating in ECO-mode?
One more thing you could try (I had the same problem occasionally, but it always magically disappeared at some point) is to change drivers/dect/coa/sc1442x.c and remove SC1442X_BC5_DO_FR from the BMC configuration. That sometimes helped in my case.
Sorry, again no luck:
diff --git a/drivers/dect/coa/sc1442x.c b/drivers/dect/coa/sc1442x.c index 9b15e81..c1cf9a8 100644 --- a/drivers/dect/coa/sc1442x.c +++ b/drivers/dect/coa/sc1442x.c @@ -911,7 +911,8 @@ static void sc1442x_write_bmc_config(const struct coa_device *dev, cfg |= 0x80; sc1442x_dwriteb(dev, off + 4, cfg);
cfg = SC1442X_BC5_DO_FR;
// cfg = SC1442X_BC5_DO_FR;cfg = 0; cfg |= tx ? SC1442X_BC5_TDO_DIGITAL : SC1442X_BC5_TDO_POWER_DOWN; sc1442x_dwriteb(dev, off + 5, cfg);
OK, I'm out of ideas currently. Just to gather some more information, are you seeing large frequency offsets on the slot where the DBC is received in dect-transceiver-list?
Am Montag, den 15.11.2010, 16:19 +0100 schrieb Patrick McHardy:
On 15.11.2010 16:14, Erik Tews wrote:
Am Montag, den 15.11.2010, 15:44 +0100 schrieb Patrick McHardy:
You could try to add to dect_mac_irc_tick, the DECT_TRANSCEIVER_UNLOCKED case, around the carrier increment:
if (net_random() > 0x7fffffff) { ... }
to have it stay on the same carrier half the time.
OK, that seems to improve the scanning results:
diff --git a/net/dect/mac_csf.c b/net/dect/mac_csf.c index a77f19f..9ec7a75 100644 --- a/net/dect/mac_csf.c +++ b/net/dect/mac_csf.c @@ -3656,9 +3656,11 @@ void dect_mac_irc_tick(struct dect_transceiver *trx)
switch (trx->state) { case DECT_TRANSCEIVER_UNLOCKED:
/* maintain scan until clock is running */irc->rx_scn = dect_next_carrier(0x3ff, irc->rx_scn);dect_set_carrier(trx, DECT_SCAN_SLOT, irc->rx_scn);
if (net_random() > 0x7fffffff) {/* maintain scan until clock is running */irc->rx_scn = dect_next_carrier(0x3ff, irc->rx_scn);dect_set_carrier(trx, DECT_SCAN_SLOT, irc->rx_scn);} break; case DECT_TRANSCEIVER_LOCK_PENDING: irc->si.ssi.pscn = dect_next_carrier(0x3ff, irc->si.ssi.pscn);However, I don't get a lock just in PP mode, if I don't use the monitor flag:
[607158.216667] com_on_air_pci 0000:02:04.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18 [607158.216679] com_on_air_pci 0000:02:04.0: setting latency timer to 64 [607158.241899] com_on_air_pci 0000:02:04.0: Loading firmware ... [607158.788708] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607192.974449] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607219.881092] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607232.329542] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607263.615645] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607283.483168] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607287.032726] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607298.211337] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607307.220212] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607370.522330] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0
The timings indicate that it only receives very few frames from the FP. Is it possible that it's operating in ECO-mode?
The Fritzbox 7270 supports ECO-mode, however I have disabled that feature in the settings dialog. However, I cannot check if ECO-mode is really disabled.
Anyway, I will upgrade my firmware to the latest version, perhaps the bug has been fixed and the new firmware operates properly now.
On 15.11.2010 16:25, Erik Tews wrote:
Am Montag, den 15.11.2010, 16:19 +0100 schrieb Patrick McHardy:
[607158.216667] com_on_air_pci 0000:02:04.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18 [607158.216679] com_on_air_pci 0000:02:04.0: setting latency timer to 64 [607158.241899] com_on_air_pci 0000:02:04.0: Loading firmware ... [607158.788708] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607192.974449] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607219.881092] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607232.329542] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607263.615645] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607283.483168] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607287.032726] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607298.211337] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607307.220212] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607370.522330] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0
The timings indicate that it only receives very few frames from the FP. Is it possible that it's operating in ECO-mode?
The Fritzbox 7270 supports ECO-mode, however I have disabled that feature in the settings dialog. However, I cannot check if ECO-mode is really disabled.
Anyway, I will upgrade my firmware to the latest version, perhaps the bug has been fixed and the new firmware operates properly now.
I own a 7240 and at least that one does properly disable ECO mode when not configured.
Am Montag, den 15.11.2010, 16:27 +0100 schrieb Patrick McHardy:
On 15.11.2010 16:25, Erik Tews wrote:
Am Montag, den 15.11.2010, 16:19 +0100 schrieb Patrick McHardy:
[607158.216667] com_on_air_pci 0000:02:04.0: PCI INT A -> GSI 18 (level, low) -> IRQ 18 [607158.216679] com_on_air_pci 0000:02:04.0: setting latency timer to 64 [607158.241899] com_on_air_pci 0000:02:04.0: Loading firmware ... [607158.788708] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607192.974449] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607219.881092] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607232.329542] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607263.615645] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607283.483168] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607287.032726] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607298.211337] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607307.220212] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0 [607370.522330] identities information: e: 0 class: 0 emc: 11d3 fpn: 0f371 rpn: 0
The timings indicate that it only receives very few frames from the FP. Is it possible that it's operating in ECO-mode?
The Fritzbox 7270 supports ECO-mode, however I have disabled that feature in the settings dialog. However, I cannot check if ECO-mode is really disabled.
Anyway, I will upgrade my firmware to the latest version, perhaps the bug has been fixed and the new firmware operates properly now.
I own a 7240 and at least that one does properly disable ECO mode when not configured.
Sorry, new firmware makes not difference here.
On 15.11.2010 15:25, Erik Tews wrote:
Am Montag, den 15.11.2010, 15:14 +0100 schrieb Patrick McHardy:
Indeed, the multi-frame resync timer has timed out (mfn:9, max is 8). It seems it didn't receive a valid tail message over the entire previous period, judging by the log. I'd guess that the transceiver has drifted off too much. You should be able to see that by watching the output of dect-transceiver-list for the slot in question.
Does locking to that PF work if you don't use monitor mode?
I will check that.
One strange thing, while scanning, I get a lot of messages with:
identities information: e: 0 class: 0 emc: ....
So my kernel finds a lot of PPs around it, but the Fritzbox is in the same room, only a few meters away, and it takes a minute or more until the Fritzbox pops up here.
As I understand the code at the moment, during the initial scan for the FP, the timing of the transmitter doesn't really matter. So we might assume that it is not a timing-problem which is responseable for this effect?
Correct, timing shouldn't matter, at least for receiving the first identity information frame from that FP. The scan isn't really optimal currently though, as soon as it has received all information from one FP, it switches to the next carrier. With some bad luck, this might cause it to miss an FP indefinitely. What it should really do is stay on the same carrier and only switch if the next FP it discovery is already known.