Improve TBF logging

use a format in tbf::name() which is sanitized (osmo_sanitize) and hence
can be used both in regular log as well as for its internal FSM ids.
Until now, the FSMs contained a small amount of information with
different formatting than the regular LOGPTFB(), which made it difficult
to grep or follow a TBF through its lifetime looking at logs. The new
unified format makes that a lot easier.

Extra information is now printed if available, such as IMSI.
Furthermore, the TFI is updated to include BTS and TRX, since the TFI is
unique within the scope of a TRX.

Change-Id: I3ce1f53942a2f881d0adadd6e5643f5cdf6e31da
diff --git a/tests/ms/MsTest.err b/tests/ms/MsTest.err
index d4895b9..51e69f7 100644
--- a/tests/ms/MsTest.err
+++ b/tests/ms/MsTest.err
@@ -1,22 +1,22 @@
 Creating MS object, TLLI = 0xffeeddbb
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Attaching UL TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=UL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, UL) Attaching DL TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=DL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Detaching TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=UL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Detaching TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=DL STATE=NEW)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Attaching UL TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, UL) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Detaching TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Detaching TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
 MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Destroying MS object
 Creating MS object, TLLI = 0xffeeddbb
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Attaching UL TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=UL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, UL) Attaching DL TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=DL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Detaching TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=UL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Detaching TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=DL STATE=NEW)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Attaching UL TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, UL) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Detaching TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Detaching TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
 MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Destroying MS object
 Creating MS object, TLLI = 0xffeeddbb
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Attaching DL TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=DL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Attaching DL TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=DL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Attaching UL TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=UL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Detaching TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=UL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Detaching TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=DL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Detaching TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=DL STATE=NEW)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Attaching UL TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Detaching TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Detaching TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Detaching TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
 MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Destroying MS object
 Creating MS object, TLLI = 0xaa000000
 Modifying MS object, UL TLLI: 0xaa000000 -> 0xff001111, not yet confirmed
@@ -41,21 +41,21 @@
 Creating MS object, TLLI = 0xffffffff
 Modifying MS object, UL TLLI: 0xffffffff -> 0xffeeddbc, not yet confirmed
 Modifying MS object, TLLI = 0xffeeddbc, IMSI '' -> '001001987654322'
-MS(TLLI=0xffeeddbb, IMSI=001001987654321, TA=220, 0/0,) Attaching UL TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=UL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=001001987654321, TA=220, 0/0,) Detaching TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=UL STATE=NEW)
+MS(TLLI=0xffeeddbb, IMSI=001001987654321, TA=220, 0/0,) Attaching UL TBF: TBF(UL:STATE-NEW:GPRS:IMSI-001001987654321:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=001001987654321, TA=220, 0/0,) Detaching TBF: TBF(UL:STATE-NEW:GPRS:IMSI-001001987654321:TLLI-0xffeeddbb)
 MS(TLLI=0xffeeddbb, IMSI=001001987654321, TA=220, 0/0,) Destroying MS object
-MS(TLLI=0xffeeddbc, IMSI=001001987654322, TA=220, 0/0,) Attaching UL TBF: TBF(TFI=-1 TLLI=0xffffffff DIR=UL STATE=NEW)
-MS(TLLI=0xffeeddbc, IMSI=001001987654322, TA=220, 0/0,) Detaching TBF: TBF(TFI=-1 TLLI=0xffffffff DIR=UL STATE=NEW)
+MS(TLLI=0xffeeddbc, IMSI=001001987654322, TA=220, 0/0,) Attaching UL TBF: TBF(UL:STATE-NEW:GPRS)
+MS(TLLI=0xffeeddbc, IMSI=001001987654322, TA=220, 0/0,) Detaching TBF: TBF(UL:STATE-NEW:GPRS)
 MS(TLLI=0xffeeddbc, IMSI=001001987654322, TA=220, 0/0,) Destroying MS object
 Creating MS object, TLLI = 0xffeeddbb
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Attaching UL TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=UL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, UL) Attaching DL TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=DL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Detaching TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=UL STATE=NEW)
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Detaching TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=DL STATE=NEW)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Attaching UL TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, UL) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0, DL) Detaching TBF: TBF(UL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Detaching TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
 MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Release timer expired
 MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Destroying MS object
 Creating MS object, TLLI = 0xffeeddbb
-MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Attaching DL TBF: TBF(TFI=-1 TLLI=0xffeeddbb DIR=DL STATE=NEW)
+MS(TLLI=0xffeeddbb, IMSI=, TA=220, 0/0,) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xffeeddbb)
 Creating MS object, TLLI = 0xdeadbeef
 Creating MS object, TLLI = 0xdeadbef0
-MS(TLLI=0xdeadbef0, IMSI=, TA=220, 0/0,) Attaching DL TBF: TBF(TFI=-1 TLLI=0xdeadbef0 DIR=DL STATE=NEW)
+MS(TLLI=0xdeadbef0, IMSI=, TA=220, 0/0,) Attaching DL TBF: TBF(DL:STATE-NEW:GPRS:TLLI-0xdeadbef0)