Re: Dectmon only recording data partially?

15 Nov 2010

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

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

Re: Dectmon only recording data partially?