Actions
Bug #4829
openOsmocomBB Rx bit errors in dedicated mode
Start date:
10/24/2020
Due date:
% Done:
40%
Resolution:
Spec Reference:
Description
I'm observing quite a number of bit errors when receiving in dedicated mode.
Those bit errors are not present while in receive-only mode (CCCH/BCCH camping.
The bit errors can be observed on SDCCH/4, SDCCH/8 and TCH/F (didn't try TCH/H).
I've tried to roll back to old OsmocomBB firmware versions as old as 2012 (using old gnuarm-4.0.x toolchain) - the problem even exists in those old versions, so it doesn't look like a regression.
I've tested with perfect RF signals (coaxial connection via attenuators) to exclude any real-world impact.
I've tested both with sysmoBTS 1002 as well as with a commercial cellular network.
I've tested with C118, C121, C123 and C140.
In all situations, the problem persists and looks like this:
Camping with good signal level 0 BER / fire_crc = 2
<000c> l1ctl.c:237 BCCH on TS0 (0301/13/02) -56 dBm 0/0: 59 06 1a 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ff e5 04 00 <000c> l1ctl.c:237 PCH/AGCH on TS0 (0301/17/06) -56 dBm 0/0: 03 03 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0301/23/12) -56 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0301/01/16) -56 dBm 0/0: 2d 06 3f 03 41 e3 67 00 68 8f 00 00 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b
Once switched to dedicated channel:
<000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0301/10/00) -56 dBm 0/0: 03 03 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0301/16/32) -56 dBm 66/2: a3 4b 33 0a 38 66 2a a4 57 cc 2e db 60 f7 e2 7e 9e cd ac d8 ee dc bd <000c> l1ctl.c:300 Dropping frame with 66 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0301/09/00) -56 dBm 74/2: a3 35 0f 0a b8 79 13 2a 6b 5e c2 da 60 f7 e2 7e 9e cd ac d8 ee dc fd <000c> l1ctl.c:300 Dropping frame with 74 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0301/08/00) -56 dBm 82/2: a3 35 0f 14 f1 f7 17 aa 57 cc 2e 12 67 f7 e2 7e 9e cd ac d8 7e 29 85 <000c> l1ctl.c:300 Dropping frame with 82 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0301/14/32) -56 dBm 77/2: a3 4b 33 0a 38 66 2a a4 57 cc 2e 92 44 f8 e2 7e 9e cd ac d8 fe 85 2f <000c> l1ctl.c:300 Dropping frame with 77 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0301/07/00) -56 dBm 74/2: a3 4b 33 0a 38 66 2a 24 6b 5e c2 da 60 f7 e2 7e 9e cd ac d8 fe 85 2f <000c> l1ctl.c:300 Dropping frame with 74 bit errors
so as we can see, he very first block is still received well, all other blocks have massive bit errors (typically in he 70..95 erroneous bit range)
Playing with the source code I could narrow it down to whether or not we are enabling the PA in the rffe_mode() function by means of tspact | PA_ENABLE
If I enable the PA only for RACH / access burst, but not for any normal bursts, the SDCCH bit errors are not reported anymore.
I've played a lot with l1s_tx_win_ctrl in terms of ordering, etc. but the problem persists.
It cannot be a general scheduling problem, as the TX window duration is not affected by whether or not we enable the PA. There are just as many TPU instructions etc. even without that one bit.
Files
| sky77324.pdf | View sky77324.pdf | 3.75 MB | PA data sheet | ||
| Sch_C118_A2_C_L3_1.0.pdf | View Sch_C118_A2_C_L3_1.0.pdf | 583 KB | C118 schematics | ||
| SF_C118_A3_C_L3_1.2.pdf | View SF_C118_A3_C_L3_1.2.pdf | 593 KB | C118 component placement (position of resistors) |
Related issues
Updated by laforge over 3 years ago
- File sky77324.pdf sky77324.pdf added
- File Sch_C118_A2_C_L3_1.0.pdf Sch_C118_A2_C_L3_1.0.pdf added
- File SF_C118_A3_C_L3_1.2.pdf SF_C118_A3_C_L3_1.2.pdf added
Ok, after another full day of debugging yesterday, I'll try to summarize my actions (and findings) here:
Bug in gsm48_rr showing SNR value as BER¶
I saw that some times, all blocks were reported with num_biterr=0 but the measurement summary still showed non-zero BER. That was just a display/printing bug (https://gerrit.osmocom.org/c/osmocom-bb/+/20864)
Nevertheless, I still see tons of blocks where the DSP reports num_biterr > 60 and fire_crc == 2 in perfect RF signal conditions, so the above was an unrelated, insignificant issue.
TPU_DEBUG¶
I extracted the TPU instructions using TPU_DEBUG. The latter first had to be fixed:- https://gerrit.osmocom.org/c/osmocom-bb/+/20880
- https://gerrit.osmocom.org/c/osmocom-bb/+/20885
- https://gerrit.osmocom.org/c/osmocom-bb/+/20886
In order to not overflow the UART, I used the non-standard high-baudrate patch from burst-ind, see laforge/baudrate.
A typical TPU window of a transmit burst looks like this:
TPU FN 1182503
0001 3284 AT 4740
4741 72e5 SYNCHRO 4837
4742 264b AT 1611
1612 8004 MOVE TSP_TX_1=0x0000
1613 9743 MOVE TSP_TX_2=0x00ba
1614 89e0 MOVE TSP_CTLR1=0x004f DEV_IDX=TRF6151, BITLEN=16 TSP_DATA=0x00ba
1615 8041 MOVE TSP_CTRL2=0x0002 WRITE
1616 92c4 MOVE TSP_TX_1=0x0096
1617 8e23 MOVE TSP_TX_2=0x0071
1618 89e0 MOVE TSP_CTLR1=0x004f DEV_IDX=TRF6151, BITLEN=16 TSP_DATA=0x9671
1619 8041 MOVE TSP_CTRL2=0x0002 WRITE
1620 9c84 MOVE TSP_TX_1=0x00e4
1621 9743 MOVE TSP_TX_2=0x00ba
1622 89e0 MOVE TSP_CTLR1=0x004f DEV_IDX=TRF6151, BITLEN=16 TSP_DATA=0xe4ba
1623 8041 MOVE TSP_CTRL2=0x0002 WRITE
1624 268e AT 1678
1679 9004 MOVE TSP_TX_1=0x0080
1680 80c0 MOVE TSP_CTLR1=0x0006 DEV_IDX=TWL3025, BITLEN=7 TSP_DATA=0x80
1681 8041 MOVE TSP_CTRL2=0x0002 WRITE
1682 a00b WAIT 11
1694 9804 MOVE TSP_TX_1=0x00c0
1695 80c0 MOVE TSP_CTLR1=0x0006 DEV_IDX=TWL3025, BITLEN=7 TSP_DATA=0xc0
1696 8041 MOVE TSP_CTRL2=0x0002 WRITE
1697 a089 WAIT 137
1835 9004 MOVE TSP_TX_1=0x0080
1836 80c0 MOVE TSP_CTLR1=0x0006 DEV_IDX=TWL3025, BITLEN=7 TSP_DATA=0x80
1837 8041 MOVE TSP_CTRL2=0x0002 WRITE
1838 a023 WAIT 35
1874 2763 AT 1891
1892 9404 MOVE TSP_TX_1=0x00a0
1893 80c0 MOVE TSP_CTLR1=0x0006 DEV_IDX=TWL3025, BITLEN=7 TSP_DATA=0xa0
1894 8041 MOVE TSP_CTRL2=0x0002 WRITE
1895 8066 MOVE TSPACT_L=0x0003 PA_ENABLE:0->1 TRENA:1->0
1896 29d7 AT 2519
2520 9004 MOVE TSP_TX_1=0x0080
2521 80c0 MOVE TSP_CTLR1=0x0006 DEV_IDX=TWL3025, BITLEN=7 TSP_DATA=0x80
2522 8041 MOVE TSP_CTRL2=0x0002 WRITE
2523 a023 WAIT 35
2559 8004 MOVE TSP_TX_1=0x0000
2560 80c0 MOVE TSP_CTLR1=0x0006 DEV_IDX=TWL3025, BITLEN=7 TSP_DATA=0x00
2561 8041 MOVE TSP_CTRL2=0x0002 WRITE
2562 8004 MOVE TSP_TX_1=0x0000
2563 9743 MOVE TSP_TX_2=0x00ba
2564 89e0 MOVE TSP_CTLR1=0x004f DEV_IDX=TRF6151, BITLEN=16 TSP_DATA=0x00ba
2565 8041 MOVE TSP_CTRL2=0x0002 WRITE
2566 8826 MOVE TSPACT_L=0x0041 PA_ENABLE:1->0 TRENA:0->1
2567 52e5 OFFSET 4837
2568 0000 SLEEP
As we can see, PA_ENABLE is present for 2566-1895 = 671 qbits only. That's 167 bits, i.e. just about one burst with a bit of lead time before and after. Exactly what is expected. PA_ENABLE is not present at times beyond that.
A typical receive TPU window looks like this:
TPU FN 1182517
0001 3284 AT 4740
4741 72e5 SYNCHRO 4837
4742 328e AT 4750
4751 8004 MOVE TSP_TX_1=0x0000
4752 9743 MOVE TSP_TX_2=0x00ba
4753 89e0 MOVE TSP_CTLR1=0x004f DEV_IDX=TRF6151, BITLEN=16 TSP_DATA=0x00ba
4754 8041 MOVE TSP_CTRL2=0x0002 WRITE
4755 94a4 MOVE TSP_TX_1=0x00a5
4756 8923 MOVE TSP_TX_2=0x0049
4757 89e0 MOVE TSP_CTLR1=0x004f DEV_IDX=TRF6151, BITLEN=16 TSP_DATA=0xa549
4758 8041 MOVE TSP_CTRL2=0x0002 WRITE
4759 93c4 MOVE TSP_TX_1=0x009e
4760 8003 MOVE TSP_TX_2=0x0000
4761 89e0 MOVE TSP_CTLR1=0x004f DEV_IDX=TRF6151, BITLEN=16 TSP_DATA=0x9e00
4762 8041 MOVE TSP_CTRL2=0x0002 WRITE
4763 8144 MOVE TSP_TX_1=0x000a
4764 9743 MOVE TSP_TX_2=0x00ba
4765 89e0 MOVE TSP_CTLR1=0x004f DEV_IDX=TRF6151, BITLEN=16 TSP_DATA=0x0aba
4766 8041 MOVE TSP_CTRL2=0x0002 WRITE
4767 3364 AT 4964
4965 8204 MOVE TSP_TX_1=0x0010
4966 80c0 MOVE TSP_CTLR1=0x0006 DEV_IDX=TWL3025, BITLEN=7 TSP_DATA=0x10
4967 8041 MOVE TSP_CTRL2=0x0002 WRITE
4968 a000 WAIT 0
4969 8304 MOVE TSP_TX_1=0x0018
4970 80c0 MOVE TSP_CTLR1=0x0006 DEV_IDX=TWL3025, BITLEN=7 TSP_DATA=0x18
4971 8041 MOVE TSP_CTRL2=0x0002 WRITE
4972 a03c WAIT 60
5033 8204 MOVE TSP_TX_1=0x0010
5034 80c0 MOVE TSP_CTLR1=0x0006 DEV_IDX=TWL3025, BITLEN=7 TSP_DATA=0x10
5035 8041 MOVE TSP_CTRL2=0x0002 WRITE
5036 2036 AT 54
0055 8284 MOVE TSP_TX_1=0x0014
0056 80c0 MOVE TSP_CTLR1=0x0006 DEV_IDX=TWL3025, BITLEN=7 TSP_DATA=0x14
0057 8041 MOVE TSP_CTRL2=0x0002 WRITE
0058 22b2 AT 690
0691 8204 MOVE TSP_TX_1=0x0010
0692 80c0 MOVE TSP_CTLR1=0x0006 DEV_IDX=TWL3025, BITLEN=7 TSP_DATA=0x10
0693 8041 MOVE TSP_CTRL2=0x0002 WRITE
0694 8004 MOVE TSP_TX_1=0x0000
0695 80c0 MOVE TSP_CTLR1=0x0006 DEV_IDX=TWL3025, BITLEN=7 TSP_DATA=0x00
0696 8041 MOVE TSP_CTRL2=0x0002 WRITE
0697 8004 MOVE TSP_TX_1=0x0000
0698 9743 MOVE TSP_TX_2=0x00ba
0699 89e0 MOVE TSP_CTLR1=0x004f DEV_IDX=TRF6151, BITLEN=16 TSP_DATA=0x00ba
0700 8041 MOVE TSP_CTRL2=0x0002 WRITE
0701 52e5 OFFSET 4837
0702 0000 SLEEP
As we can see, no fiddling with the PA enable line anywhere.
So nothing out of the ordinary is observed here.
hardware disabling PAENE signal¶
I excluded any impact by software by de-soldering R67 on my C123 (0-ohm resistor in-line with the PAEN signal). Unfortunately that of course means I can no longe send a RACH request and hence not establish a channel.
I used radio-link-timeout infinite and manual activation of the SDCCH/8(0) on TS1 on the BTS/BSC side, and injected a fake "IMMEDIATE ASSIGN" to mobile to get the channel activated on both sides.
Using an unmodified normal firmware with TX enabled and PAENA signal connected (R67 placed) always showed the bit errors. Removing R67 with identical firmware makes the bit errors go away. All downlink blocks are now received free of errors.
So we have concluded that it must be some kind of physical effect caused by the PA being enabled.
hardware disabling APC signal¶
With PAEN re-connected via R67, I soldered a 10 Ohms resistor parallel to C99. This effectively disable the APC bias voltage.
Interestingly, the results were different from the tests above with PAENA disabled.
With VAPC grounded, The MS was no longer able to transmit. However, the downlink BER problems still persisted!
So we can summarize:- Disabling the PA via PAENA: downlink BER disappears
- Disabling the PA via APC: downlink BER remains.
At least according to the C118 schematics (I don't think we ever had those for the C123), the PAENA signal doesn't connect anywhere else. so unless there's some hardware bug (appearing in multiple phones at the same time!), The PA must be causing the problem.
reducing /increasing transmit power¶
All previous tests of the past days were performed using 16 dBm MS-side transmit power (via ms power max in osmo-bsc.cfg).
After re-enabling PAENA and APC:
I tested with 30dBm and 0dBm transmit power on the MS side. In all cases, even with the low 0dBm transmit power, the downlink BER problem appears.
Transmit power was actually confirmed to be reduced in the 0dBm case, as I had to remove lots of attenuation from the RF path to make the RACH actually still reach the BTS at 0dBm transmit power.
We can summarize:- the amount of gain / RF transmit power in the PA does not impact the number of BER in downlink
comparing commercial networks with osmo-bts-sysmo¶
It can be seen that the high downlink BER in the commercial network only appears on the SACCH of a SDCCH/8, while in my lab setup with osmo-bts-sysmo it appears on both SDCCH/8 and the associated SACCH. So there may be another problem there?
Updated by laforge over 3 years ago
Some more log output:
on osmo-bts-sysmo¶
<000c> l1ctl.c:237 BCCH on TS0 (0821/17/02) -70 dBm 0/0: 59 06 1a 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ff e5 04 00 <0003> gsm48_rr.c:4835 Channel provides data. <0003> gsm322.c:703 Starting CS timer with 4 seconds. <0001> gsm48_rr.c:1829 New SYSTEM INFORMATION 2 <000c> l1ctl.c:237 BCCH on TS0 (0821/16/02) -70 dBm 0/0: 49 06 1b 1b 39 00 f1 10 00 01 c8 03 05 27 47 40 e5 04 00 2c 0b 2b 2b <0001> sysinfo.c:703 New SYSTEM INFORMATION 3 (mcc 001 mnc 01 lac 0x0001) <0001> gsm48_rr.c:1920 Changing CCCH_MODE to 1 <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/00/12) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/04/16) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/10/22) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/14/26) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/20/32) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/24/36) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/04/42) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/08/46) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 BCCH on TS0 (0821/15/02) -70 dBm 0/0: 31 06 1c 00 f1 10 00 01 47 40 e5 04 00 01 2b 2b 2b 2b 2b 2b 2b 2b 2b <0001> gsm48_rr.c:1952 New SYSTEM INFORMATION 4 (mcc 001 mnc 01 lac 0x0001) <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/19/06) -70 dBm 0/0: 03 03 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/25/12) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/03/16) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/09/22) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/13/26) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/19/32) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/23/36) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/03/42) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/07/46) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 BCCH on TS0 (0821/14/02) -70 dBm 0/0: 55 06 19 8f b3 80 00 00 00 00 00 00 00 00 00 00 00 00 00 e5 04 00 2b <0001> sysinfo.c:615 Now updating previously received SYSTEM INFORMATION 4 <0001> gsm48_rr.c:1800 New SYSTEM INFORMATION 1 <0003> gsm322.c:2721 Received relevant sysinfo. <0003> gsm322.c:713 stopping pending CS timer. <0003> gsm322.c:2327 Scan frequency 871(DCS): Cell found. (rxlev -70 mcc 001 mnc 01 lac 0001) <0003> gsm322.c:1841 Select using access class <0003> gsm322.c:383 A (RLA_C (-70) - RXLEV_ACC_MIN (-110)) = 40 <0003> gsm322.c:385 B (MS_TXPWR_MAX_CCH (16) - p (30)) = -14 <0003> gsm322.c:387 C1 (A - MAX(B,0)) = 40 <0003> gsm322.c:1955 Cell ARFCN 871(DCS): Cell found, (rxlev=-70 mcc=001 mnc=01 lac=0001 Test, Test) <0003> gsm322.c:1970 Cell ARFCN 871(DCS) selected. <0003> gsm322.c:2428 Tune to frequency 871. <0003> gsm322.c:470 Sync to ARFCN=871(DCS) rxlev=-70 (Sysinfo, ccch mode NON-COMB) <0003> gsm322.c:2455 Cell available. <0003> gsm322.c:4060 (ms 1) Event 'EVENT_CELL_FOUND' for Cell selection in state 'C2 stored cell selection' <000e> gsm322.c:3392 Camping normally on cell (ARFCN=871(DCS) mcc=001 mnc=01 Test, Test) <0003> gsm322.c:833 new state 'C2 stored cell selection' -> 'C3 camped normally' <0005> gsm48_mm.c:4305 (ms 1) Received 'MM_EVENT_CELL_SELECTED' event in state MM IDLE, PLMN search <0005> gsm48_mm.c:904 new MM IDLE state PLMN search -> location updating needed <0005> gsm48_mm.c:904 new MM IDLE state location updating needed -> attempting to update <0005> gsm48_mm.c:424 starting T3212 (periodic loc. upd. delay) with 1800 seconds <0005> gsm48_mm.c:2289 Do normal Loc. upd. <000e> gsm48_mm.c:2204 Perform location update (MCC 001, MNC 01 LAC 0x0001) <0005> gsm48_mm.c:2340 LOCATION UPDATING REQUEST <0005> gsm48_mm.c:2360 using LAI (mcc 001 mnc 01 lac 0xfffe) <0005> gsm48_mm.c:2373 using IMSI 001010000000001 <0005> gsm48_mm.c:909 new state MM IDLE, attempting to update -> wait for RR connection (location updating) <0001> gsm48_rr.c:5462 (ms 1) Message 'RR_EST_REQ' received in state idle (sapi 0) <000e> gsm48_rr.c:1299 Establish radio link due to mobility management request <0003> gsm322.c:4060 (ms 1) Event 'EVENT_LEAVE_IDLE' for Cell selection in state 'C3 camped normally' <0003> gsm322.c:833 new state 'C3 camped normally' -> 'connected mode 1' <0003> gsm322.c:3677 Going to camping (normal) ARFCN 871(DCS). <0003> gsm322.c:456 Sync to ARFCN=871(DCS), but there is a sync already pending <0001> gsm48_rr.c:359 new state idle -> connection pending <0001> gsm48_rr.c:1446 CHANNEL REQUEST: 00 (Location Update with NECI) <0003> gsm322.c:2956 Channel synched. (ARFCN=871(DCS), snr=16, BSIC=63) <0001> gsm322.c:2979 using DSC of 90 <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/06/46) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <0003> gsm48_rr.c:4835 Channel provides data. <0001> gsm48_rr.c:1587 RANDOM ACCESS (requests left 8) <0001> gsm48_rr.c:1643 RANDOM ACCESS (Tx-integer 12 combined no S(lots) 0 ra 0x0c) <0001> gsm48_rr.c:1680 Use MS-TXPWR-MAX-CCH power value 7 (16 dBm) <000c> l1ctl.c:237 BCCH on TS0 (0821/13/02) -70 dBm 0/0: 59 06 1a 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 ff e5 04 00 <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/17/06) -70 dBm 0/0: 03 03 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <0001> gsm48_rr.c:1587 RANDOM ACCESS (requests left 7) <0001> gsm48_rr.c:1643 RANDOM ACCESS (Tx-integer 12 combined no S(lots) 217 ra 0x0f) <0001> gsm48_rr.c:1680 Use MS-TXPWR-MAX-CCH power value 7 (16 dBm) <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/23/12) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/01/16) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/07/22) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/11/26) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0821/17/32) -70 dBm 0/0: 2d 06 3f 03 41 e3 67 0c a9 97 00 00 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <0001> gsm48_rr.c:2439 IMMEDIATE ASSIGNMENT: <0001> gsm48_rr.c:2457 (ta 0/0m ra 0x0c chan_nr 0x41 ARFCN 871(DCS) TS 1 SS 0 TSC 7) <0001> gsm48_rr.c:2487 resetting scheduler <0001> gsm48_rr.c:3228 sending establish message <0001> gsm48_rr.c:231 Using and incrementing V(SD) = 0 (pdisc 5) <0001> gsm48_rr.c:2964 setting indicated TA 0 (actual TA 0) <0001> gsm48_rr.c:2979 using last BCCH timeout 32 <0001> gsm48_rr.c:825 stopping pending timer T_meas <0001> gsm48_rr.c:2860 MEAS REP: pwr=7 TA=0 meas-invalid=1 rxlev-full=-110 rxlev-sub=-110 rxqual-full=0 rxqual-sub=0 dtx 0 ba 0 no-ncell-n 7 <0001> gsm48_rr.c:2998 establishing channel in dedicated mode <0001> gsm48_rr.c:3000 Channel type 64, subch 0, ts 1, mode 0, audio-mode 5, cipher 1 <000c> l1ctl.c:237 PCH/AGCH on TS1 (0821/21/36) -70 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/10/00) -70 dBm 0/0: 03 03 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/16/32) -70 dBm 71/2: 23 4b a3 17 f1 f7 c7 24 fb 96 85 48 45 f8 e2 0c 32 f1 ac d8 7e 29 c5 <000c> l1ctl.c:300 Dropping frame with 71 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/09/00) -70 dBm 73/2: 23 4b a3 17 f1 f7 37 63 19 5e c2 da 60 f7 e2 7e 9e cd ac d8 ee fc 2f <000c> l1ctl.c:300 Dropping frame with 73 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/08/00) -70 dBm 69/2: 23 4b a3 17 f1 f7 47 63 3d 97 a1 c7 5d f9 e2 5e e7 b9 ac d8 b6 71 2e <000c> l1ctl.c:300 Dropping frame with 69 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/14/32) -70 dBm 78/2: a3 6f da 0b 38 d4 6e aa 57 cc 2e 12 7e f8 e2 5e 87 f2 ac d8 ee dc bd <000c> l1ctl.c:300 Dropping frame with 78 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/07/00) -70 dBm 71/2: a3 4b a3 17 f1 f7 37 63 19 5e a6 c7 79 f8 e2 5e 87 f2 ac d8 ee dc bd <000c> l1ctl.c:300 Dropping frame with 71 bit errors <0001> gsm48_rr.c:667 MON: f=871 lev=-70 snr=26 ber= 52 LAI=001 01 0001 ID=1b39 <0001> gsm48_rr.c:2860 MEAS REP: pwr=7 TA=0 meas-invalid=0 rxlev-full=-70 rxlev-sub=-70 rxqual-full=0 rxqual-sub=0 dtx 0 ba 0 no-ncell-n 7 <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/06/00) -70 dBm 71/2: a3 6f da 0b 38 d4 6e aa 17 de 17 00 67 f7 e2 ec 11 f1 ac d8 ee dc bd <000c> l1ctl.c:300 Dropping frame with 71 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/12/32) -70 dBm 74/2: a3 6f 5a 2f f1 f7 5f b8 1e 5e a6 76 43 f8 22 ef ba 84 ac d8 ee dc c4 <000c> l1ctl.c:300 Dropping frame with 74 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/05/00) -70 dBm 74/2: a3 6f da 0b 38 d4 4e 63 19 5e c2 da 60 f7 e2 5e 87 cc ac d8 7e a9 bd <000c> l1ctl.c:300 Dropping frame with 74 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/04/00) -70 dBm 73/2: 23 4b a3 17 f1 f7 47 63 19 5e c2 da 60 f7 e2 5e 87 cc ac d8 7e b8 bd <000c> l1ctl.c:300 Dropping frame with 73 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/10/32) -70 dBm 80/2: 87 4c a3 17 f1 f7 57 58 1f 5e e6 71 43 b0 54 42 bc cc ac d8 ee fc 2f <000c> l1ctl.c:300 Dropping frame with 80 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/03/00) -70 dBm 71/2: 87 4c a3 17 f1 f7 37 63 19 5e c2 da 60 77 ff 45 bc 84 ac d8 ee dc bd <000c> l1ctl.c:300 Dropping frame with 71 bit errors <000c> l1ctl.c:237 SDCCH/8(0) on TS1 (0821/02/00) -70 dBm 72/2: 23 4b a3 17 f1 f7 c7 24 fb 96 85 48 45 f8 e2 7e 9e cd ac d8 ee dc bd <000c> l1ctl.c:300 Dropping frame with 72 bit errorsWe can see:
- BCCH and PCH/AGCH blocks always have 0/0 (num_biterr/fire_crc)
- we get a strange "PCH/AGCH on TS1" block while switching to dedicated mode
- the first SDCCH/8(0) block is received with 0/0
- all follow-up SDCCH/8(0) blocks both on SDCCH (/00) and on SACCH (/32) have massive num_biterr + fire_crc=2
on a commercial cell¶
<000c> l1ctl.c:237 BCCH on TS0 (0782/25/02) -91 dBm 0/0: 31 06 1c 62 f2 10 37 21 65 44 a4 00 00 43 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/03/06) -91 dBm 0/0: 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/09/12) -91 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/13/16) -91 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/19/22) -91 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/23/26) -91 dBm 0/0: 2d 06 22 00 e3 cf 70 60 ef ce d0 d3 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <0001> gsm48_rr.c:2214 PAGING ignored, we are not camping. <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/03/32) -91 dBm 0/0: 25 06 21 00 05 f4 de db 28 aa 23 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <0001> gsm48_rr.c:2159 PAGING ignored, we are not camping. <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/07/36) -91 dBm 0/0: 55 06 22 00 f0 db 19 1d de df 99 a0 17 08 29 23 30 81 02 77 58 52 8b <0001> gsm48_rr.c:2214 PAGING ignored, we are not camping. <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/13/42) -91 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/17/46) -91 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 BCCH on TS0 (0782/24/02) -91 dBm 0/0: 55 06 19 00 90 00 00 00 00 08 08 00 10 00 00 00 00 00 00 a4 00 00 2b <0001> sysinfo.c:615 Now updating previously received SYSTEM INFORMATION 4 <0001> gsm48_rr.c:1800 New SYSTEM INFORMATION 1 <0003> gsm322.c:2721 Received relevant sysinfo. <0003> gsm322.c:713 stopping pending CS timer. <0003> gsm322.c:2327 Scan frequency 120: Cell found. (rxlev <=-110 mcc 262 mnc 01 lac 3721) <0003> gsm322.c:1841 Select using access class <0003> gsm322.c:383 A (RLA_C (-110) - RXLEV_ACC_MIN (-106)) = -4 <0003> gsm322.c:385 B (MS_TXPWR_MAX_CCH (33) - p (33)) = 0 <0003> gsm322.c:387 C1 (A - MAX(B,0)) = -4 <0003> gsm322.c:1955 Cell ARFCN 120: Cell found, (rxlev=<=-110 mcc=262 mnc=01 lac=3721 Germany, T-Mobile) <0003> gsm322.c:1970 Cell ARFCN 120 selected. <0003> gsm322.c:2428 Tune to frequency 120. <0003> gsm322.c:470 Sync to ARFCN=120 rxlev=<=-110 (Sysinfo, ccch mode NON-COMB) <0003> gsm322.c:2455 Cell available. <0003> gsm322.c:4060 (ms 1) Event 'EVENT_CELL_FOUND' for Cell selection in state 'C2 stored cell selection' <000e> gsm322.c:3392 Camping normally on cell (ARFCN=120 mcc=262 mnc=01 Germany, T-Mobile) <0003> gsm322.c:833 new state 'C2 stored cell selection' -> 'C3 camped normally' <0005> gsm48_mm.c:4305 (ms 1) Received 'MM_EVENT_CELL_SELECTED' event in state MM IDLE, PLMN search <0005> gsm48_mm.c:904 new MM IDLE state PLMN search -> location updating needed <0005> gsm48_mm.c:904 new MM IDLE state location updating needed -> attempting to update <0005> gsm48_mm.c:424 starting T3212 (periodic loc. upd. delay) with 10800 seconds <0005> gsm48_mm.c:2289 Do normal Loc. upd. <000e> gsm48_mm.c:2204 Perform location update (MCC 262, MNC 01 LAC 0x3721) <0005> gsm48_mm.c:2340 LOCATION UPDATING REQUEST <0005> gsm48_mm.c:2360 using LAI (mcc 001 mnc 01 lac 0xfffe) <0005> gsm48_mm.c:2373 using IMSI 001010000000001 <0005> gsm48_mm.c:909 new state MM IDLE, attempting to update -> wait for RR connection (location updating) <0001> gsm48_rr.c:5462 (ms 1) Message 'RR_EST_REQ' received in state idle (sapi 0) <000e> gsm48_rr.c:1299 Establish radio link due to mobility management request <0003> gsm322.c:4060 (ms 1) Event 'EVENT_LEAVE_IDLE' for Cell selection in state 'C3 camped normally' <0003> gsm322.c:833 new state 'C3 camped normally' -> 'connected mode 1' <0003> gsm322.c:3677 Going to camping (normal) ARFCN 120. <0003> gsm322.c:456 Sync to ARFCN=120, but there is a sync already pending <0001> gsm48_rr.c:359 new state idle -> connection pending <0001> gsm48_rr.c:1446 CHANNEL REQUEST: 00 (Location Update with NECI) <0003> gsm322.c:2956 Channel synched. (ARFCN=120, snr=16, BSIC=10) <0001> gsm322.c:2979 using DSC of 90 <0001> gsm48_rr.c:667 MON: no cell info <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/16/46) -90 dBm 0/0: 49 06 22 00 c8 bd 18 93 d6 ae 29 23 17 05 f4 fd ca 08 ea 8a 2b 2b 2b <0003> gsm48_rr.c:4835 Channel provides data. <0001> gsm48_rr.c:1587 RANDOM ACCESS (requests left 5) <0001> gsm48_rr.c:1643 RANDOM ACCESS (Tx-integer 12 combined no S(lots) 0 ra 0x08) <0001> gsm48_rr.c:1680 Use MS-TXPWR-MAX-CCH power value 5 (33 dBm) <000c> l1ctl.c:237 BCCH on TS0 (0782/23/02) -90 dBm 0/0: 59 06 1a 0a 01 00 00 00 14 a0 83 01 84 00 00 00 00 00 00 8f a4 00 00 <0001> gsm48_rr.c:1587 RANDOM ACCESS (requests left 4) <0001> gsm48_rr.c:1643 RANDOM ACCESS (Tx-integer 12 combined no S(lots) 217 ra 0x01) <0001> gsm48_rr.c:1680 Use MS-TXPWR-MAX-CCH power value 5 (33 dBm) <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/01/06) -90 dBm 0/0: 01 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/07/12) -90 dBm 0/0: 15 06 21 00 01 f0 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <000c> l1ctl.c:237 PCH/AGCH on TS0 (0782/11/16) -90 dBm 0/0: 2d 06 3f 00 49 40 78 08 70 e2 01 00 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <0001> gsm48_rr.c:2439 IMMEDIATE ASSIGNMENT: <0001> gsm48_rr.c:2457 (ta 1/553m ra 0x08 chan_nr 0x49 ARFCN 120 TS 1 SS 1 TSC 2) <0001> gsm48_rr.c:2487 resetting scheduler <0001> gsm48_rr.c:3228 sending establish message <0001> gsm48_rr.c:231 Using and incrementing V(SD) = 0 (pdisc 5) <0001> gsm48_rr.c:2964 setting indicated TA 1 (actual TA 1) <0001> gsm48_rr.c:2979 using last BCCH timeout 24 <0001> gsm48_rr.c:825 stopping pending timer T_meas <0001> gsm48_rr.c:2860 MEAS REP: pwr=5 TA=1 meas-invalid=1 rxlev-full=-110 rxlev-sub=-110 rxqual-full=0 rxqual-sub=0 dtx 0 ba 0 no-ncell-n 7 <0001> gsm48_rr.c:2998 establishing channel in dedicated mode <0001> gsm48_rr.c:3000 Channel type 64, subch 1, ts 1, mode 0, audio-mode 5, cipher 1 <000c> l1ctl.c:237 PCH/AGCH on TS1 (0782/17/22) -90 dBm 62/0: 25 06 21 00 05 f4 f4 af c2 da 23 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b 2b <0001> gsm48_rr.c:2159 PAGING ignored, we are not camping. <000c> l1ctl.c:237 SDCCH/8(1) on TS1 (0782/24/04) -89 dBm 0/0: 03 03 01 2b 33 53 af ce 5e c3 09 f3 92 80 19 6d 18 ab ba 57 97 4c 4e <000c> l1ctl.c:237 SDCCH/8(1) on TS1 (0782/04/36) -90 dBm 0/0: 05 01 03 03 49 06 1d 0a 01 00 00 00 14 a0 83 01 84 00 00 00 00 00 00 <0015> lapdm.c:762 Received frame for unsupported SAPI 1! <000c> l1ctl.c:237 SDCCH/8(1) on TS1 (0782/23/04) -89 dBm 0/0: 01 73 49 05 08 70 00 f1 10 ff fe 30 08 09 10 10 00 00 00 00 10 2b 92 <000e> gsm48_rr.c:3356 Radio link is released <0001> gsm48_rr.c:779 starting T_rel_wait with 1.500 seconds <0001> gsm48_rr.c:359 new state connection pending -> release pending <0005> gsm48_mm.c:3902 (ms 1) Received 'RR_REL_IND' from RR in state wait for RR connection (location updating) (sapi 0) <0005> gsm48_mm.c:2739 RR link released after loc. upd. <000e> gsm48_mm.c:2683 Location update failed <0005> subscriber.c:1074 (ms 1) new state U2_NOT_UPDATED -> U2_NOT_UPDATED <000e> gsm48_mm.c:2722 Try location update later <0005> gsm48_mm.c:1086 Not camping, wait for CS process to camp, it sends us CELL_SELECTED then. <000c> l1ctl.c:237 SDCCH/8(1) on TS1 (0782/22/04) -90 dBm 0/0: 03 00 0d 05 04 0b 2b de 9d 98 69 aa ae ff 3c 40 11 f0 0c 44 05 f3 43 <0015> lapd_core.c:1498 (dl=0x62c000000bd8) I frame ignored in state LAPD_STATE_IDLE <000c> l1ctl.c:237 SDCCH/8(1) on TS1 (0782/02/36) -89 dBm 79/2: b1 14 86 36 ee 66 68 16 65 be 70 c0 0d 8a 96 d0 33 17 2c 70 08 5d 21 <000c> l1ctl.c:300 Dropping frame with 79 bit errors <000c> l1ctl.c:237 SDCCH/8(1) on TS1 (0782/21/04) -89 dBm 0/0: 03 03 01 2b 92 c7 2d 92 9d ad a9 bd be f1 b0 44 74 33 67 55 ea bf 0f <0001> gsm48_rr.c:667 MON: f=120 lev=-89 snr=57 ber= 20 LAI=262 01 3721 ID=21a2 <0001> gsm48_rr.c:2860 MEAS REP: pwr=5 TA=1 meas-invalid=0 rxlev-full=-89 rxlev-sub=-89 rxqual-full=0 rxqual-sub=0 dtx 0 ba 0 no-ncell-n 7 <000c> l1ctl.c:237 SDCCH/8(1) on TS1 (0782/20/04) -89 dBm 0/0: 03 10 0d 05 04 0b 2b de 9d 98 69 aa ae ff 3c 40 11 f0 0c 44 05 f3 43 <0015> lapd_core.c:1498 (dl=0x62c000000bd8) I frame ignored in state LAPD_STATE_IDLE <000c> l1ctl.c:237 SDCCH/8(1) on TS1 (0782/00/36) -89 dBm 82/2: f5 42 53 b8 04 77 e1 f5 bd 14 26 4e 45 a8 99 d0 c3 ff bd 6d 08 5d 21 <000c> l1ctl.c:300 Dropping frame with 82 bit errors <000c> l1ctl.c:237 SDCCH/8(1) on TS1 (0782/19/04) -90 dBm 0/0: 03 03 01 2b 41 f4 30 47 54 32 bf 55 b0 3f 34 10 17 4c 0e b5 c4 77 13 <000c> l1ctl.c:237 SDCCH/8(1) on TS1 (0782/18/04) -90 dBm 0/0: 03 10 0d 05 04 0b 2b de 9d 98 69 aa ae ff 3c 40 11 f0 0c 44 05 f3 43 <0015> lapd_core.c:1498 (dl=0x62c000000bd8) I frame ignored in state LAPD_STATE_IDLE <000c> l1ctl.c:237 SDCCH/8(1) on TS1 (0782/24/36) -89 dBm 85/2: 3d 31 6f 36 ee e6 54 1e bd 14 7f c0 29 95 4e f3 fa ed 64 db 14 86 02 <000c> l1ctl.c:300 Dropping frame with 85 bit errors <000c> l1ctl.c:237 SDCCH/8(1) on TS1 (0782/17/04) -90 dBm 0/0: 03 03 01 2b 0b 24 07 5b 42 bb 71 b3 64 75 eb 67 0f 6a 84 2f 23 5c 19
we can observe everything like in the above trace, but the num_biterr/fire_crc problems only on the SACCH (/36 here), and not on the main SDCCH (/04 here).
Updated by laforge over 3 years ago
re-tried with osmo-bts-trx - behavior is identical. no BER on SDCCH, and then significant number of bit errors on the dedicated channel
Updated by laforge over 3 years ago
- % Done changed from 0 to 40
So.... the problem is something else altogether, or at least a large part of the problem.
When testing RF related stuff, I typically never bother much about the CN. All I need is a working RAN with BTS + BSC, and the MS. After all, I don't care about what happens on L3 or higher.
For some reason, osmo-bsc these days immediately hard-releases the lchan if there is no MSC. There is no signalign sent back to the MS about this:- no spoofing of MM/CM (LU REJECT, CM SERV REJECT, ...) which is still understandable, as it's a layering violation and those messages normally originat e at the MSC
- No RR CHANNEL RELEASE is sent to the MS. That is a big fat bug.
Instead, we simply immedaitely close the lchan on the BTS side. This of course means that from that point onwards there re only bit-errors in downlink in the UE.
DRSL INFO <0003> ../../../git/src/osmo-bsc/abis_rsl.c:1453 (bts=0) CHAN RQD: reason: Location updating (ra=0x0f, neci=0x01, chreq_reason=0x03)
DCHAN INFO <000f> ../../../git/src/osmo-bsc/lchan_select.c:247 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{UNUSED}: (type=SDCCH) Selected
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1657 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{UNUSED}: (type=SDCCH) MS: Channel Request: reason=LOCATION_UPDATE ra=0x0f ta=0
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:329 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{UNUSED}: Received Event LCHAN_EV_ACTIVATE
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:548 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{UNUSED}: state_chg to WAIT_TS_READY
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/gsm_data.c:861 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_TS_READY}: (type=SDCCH) MS Power level update requested: 15 dBm
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/gsm_data.c:893 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_TS_READY}: (type=SDCCH) MS Power level update (power class 0): 0 -> 7
DCHAN INFO <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:626 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_TS_READY}: (type=SDCCH) Activation requested: FOR_MS_CHANNEL_REQUEST voice=no MGW-ci=none type=SDCCH tch-mode=SIGNALLING encr-alg=A5/0 ck=none
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/timeslot_fsm.c:106 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_TS_READY}: Received Event LCHAN_EV_TS_READY
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:644 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_TS_READY}: state_chg to WAIT_ACTIV_ACK
DRSL DEBUG <0003> ../../../git/src/osmo-bsc/abis_rsl.c:476 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4,state=IN_USE) Tx RSL Channel Activate with act_type=INITIAL
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1152 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_ACTIV_ACK}: (type=SDCCH) Rx CHAN_ACTIV_ACK
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1164 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_ACTIV_ACK}: Received Event LCHAN_EV_RSL_CHAN_ACTIV_ACK
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:772 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_ACTIV_ACK}: (type=SDCCH) Tx RR Immediate Assignment
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:822 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_ACTIV_ACK}: state_chg to WAIT_RLL_RTP_ESTABLISH
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1899 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RLL_RTP_ESTABLISH}: (type=SDCCH) SAPI=0 ESTABLISH INDICATION
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1932 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RLL_RTP_ESTABLISH}: Received Event LCHAN_EV_RLL_ESTABLISH_IND
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:850 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RLL_RTP_ESTABLISH}: state_chg to ESTABLISHED
DRSL ERROR <0003> ../../../git/src/osmo-bsc/gsm_08_08.c:483 MM GSM48_MT_MM_LOC_UPD_REQUEST: IMSI-001010000000001: No suitable MSC for this Complete Layer 3 request found
DRSL DEBUG <0003> ../../../git/src/osmo-bsc/abis_rsl.c:644 (bts=0,trx=0,ts=0,ss=0) DEACTivate SACCH CMD
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:1595 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{ESTABLISHED}: state_chg to WAIT_RF_RELEASE_ACK
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/bsc_subscr_conn_fsm.c:778 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RF_RELEASE_ACK}: conn SUBSCR_CONN(msc4294967295-conn4294967295_subscr-IMSI-001010000000001)[0x28adc0] detaches lchan (primary lchan)
DMSC ERROR <0007> ../../../git/src/osmo-bsc/bsc_subscr_conn_fsm.c:153 SUBSCR_CONN(msc4294967295-conn4294967295_subscr-IMSI-001010000000001)[0x28adc0]{INIT}: Unable to deliver BSSMAP Clear Request message, no MSC for this conn
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:1644 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RF_RELEASE_ACK}: lchan detaches from conn SUBSCR_CONN(msc4294967295-conn4294967295_subscr-IMSI-001010000000001)[0x28adc0]
DLINP ERROR <0017> ../../git/src/input/ipaccess.c:412 Bad signalling message, sign_link returned error: No such file or directory.
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1152 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RF_RELEASE_ACK}: (type=SDCCH) Rx RF_CHAN_REL_ACK
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/abis_rsl.c:1184 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RF_RELEASE_ACK}: Received Event LCHAN_EV_RSL_RF_CHAN_REL_ACK
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:1206 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_RF_RELEASE_ACK}: state_chg to WAIT_AFTER_ERROR
DLSS7 ERROR <0021> ../../git/src/m3ua.c:507 XUA_AS(as-clnt-A-0-m3ua)[0x253d70]{AS_DOWN}: Event AS-TRANSFER.req not permitted
DCHAN DEBUG <000f> ../../git/src/fsm.c:322 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_AFTER_ERROR}: Timeout of X3111
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:1550 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{WAIT_AFTER_ERROR}: state_chg to UNUSED
DCHAN DEBUG <000f> ../../../git/src/osmo-bsc/lchan_fsm.c:382 lchan(0-0-0-CCCH_SDCCH4-0)[0x28a0d0]{UNUSED}: (type=SDCCH) Clearing lchan state
Now if I disable transmit in the UE (by disabling the PA), then of course the first uplink message is never sent, which means the BSC keeps the channel open, which means there are no bit errors. doh.
Updated by laforge over 3 years ago
- Related to Bug #4832: osmo-bsc hard-releases lchan if no MSC is found added
Actions
