Project

General

Profile

Bug #2187

ofono: not all modems do what they should

Added by neels 5 months ago. Updated 12 days ago.

Status:
New
Priority:
Low
Assignee:
Target version:
-
Start date:
04/25/2017
Due date:
% Done:

84%

Spec Reference:

Description

This is a combined report of what the 4 modems currently connected to the gsm-tester R&D setup can and cannot do.
Individual issues will be created as subtasks.


Subtasks

Bug #2188: ofono: Gobi modem refuses to set Online=trueClosedneels

Bug #2189: ofono: EC20: cannot send SMSNewlynxis

Bug #2473: update EC20 to a newer firmwareResolvedlynxis

Bug #2190: ofono: no NetworkRegistration interfaceClosedlynxis

Bug #2238: ofono: Gobi modem: cannot receive SMSNewlynxis

Bug #2239: ofono: USSD is not implemented for any modemStalledlynxis

Bug #2240: ofono: voice calls are not implemented for any modemFeedbackpespin

Bug #2471: update sierra 7304 to a voice firmwareResolvedlynxis

Bug #2421: ofono: Gobi modem: Refuses to Power onResolvedlynxis


Related issues

Related to OsmoGSMTester - Bug #2237: ofono: Gobi modem: successful SMS delivery is evaluated as not successful Feedback 05/05/2017

History

#1 Updated by neels 5 months ago

Did the following on all four modems:

  • power off
  • power on
  • set online = true (indeed equivalent to "flight mode off")
  • send SMS from all four to one particular subscriber
  • monitor whether that subscriber receives the SMS from the other three and itself

Summary:

- Gobi: /gobi_1 refuses to go Online=true (hence no attach and can't test SMS send/receive)
- EC20: /gobi_0 and /gobi_2 receive SMS fine, but sent SMS get lost = never reach the NITB
- Sierra Wireless: /sierra_2 does everything as expected

#2 Updated by neels 5 months ago

Lots of dumps:
(submitted in parts because redmine is giving me an internal error for the whole lot in one)

dbus path model imsi msisdn
/gobi_0 EC20 901700000009030 48292
/gobi_1 Gobi 901700000009031 22771
/sierra_2 Sierra Wireless 901700000009029 39631
/gobi_3 EC20 901700000009032 45678

dbus commands:

root@apu-roh:~# for m in /gobi_0 /gobi_1 /sierra_2 /gobi_3 ; do echo; echo; echo $m ; mdbus2 -s org.ofono $m org.ofono.Modem.SetProperty Powered false; done

/gobi_0
()

/gobi_1
()

/sierra_2
()

/gobi_3
()
root@apu-roh:~# for m in /gobi_0 /gobi_1 /sierra_2 /gobi_3 ; do echo; echo; echo $m ; mdbus2 -s org.ofono $m org.ofono.Modem.SetProperty Powered true; done

/gobi_0
()

/gobi_1
()

/sierra_2
()

/gobi_3
()
root@apu-roh:~# for m in /gobi_0 /gobi_1 /sierra_2 /gobi_3 ; do echo; echo; echo $m ; mdbus2 -s org.ofono $m org.ofono.Modem.GetProperties; done

/gobi_0
({'Online': <false>, 'Powered': <true>, 'Lockdown': <false>, 'Emergency': <false>, 'Manufacturer': <'Quectel'>, 'Model': <'EC20'>, 'Revision': <'EC20EQAR02A05E2G  1  [Mar 14 2016 19:33:01]'>, 'Serial': <'20120822'>, 'Interfaces': <['org.ofono.SmartMessaging', 'org.ofono.PushNotification', 'org.ofono.MessageManager', 'org.ofono.RadioSettings', 'org.ofono.AllowedAccessPoints', 'org.ofono.SimManager', 'org.ofono.LocationReporting', 'org.ofono.VoiceCallManager']>, 'Features': <['sms', 'rat', 'sim', 'gps']>, 'Type': <'hardware'>},)

/gobi_1
({'Online': <false>, 'Powered': <true>, 'Lockdown': <false>, 'Emergency': <false>, 'Manufacturer': <'Qualcomm Incorporated'>, 'Model': <'12'>, 'Revision': <'D1025-STUTABGD-3574  1  [Apr 07 2009 19:00:00]'>, 'Serial': <'806815D7'>, 'Interfaces': <['org.ofono.SmartMessaging', 'org.ofono.PushNotification', 'org.ofono.MessageManager', 'org.ofono.RadioSettings', 'org.ofono.SimManager', 'org.ofono.LocationReporting', 'org.ofono.AllowedAccessPoints']>, 'Features': <['sms', 'rat', 'sim', 'gps']>, 'Type': <'hardware'>},)

/sierra_2
({'Online': <false>, 'Powered': <true>, 'Lockdown': <false>, 'Emergency': <false>, 'Manufacturer': <'Sierra Wireless, Incorporated'>, 'Model': <'MC7304'>, 'Revision': <'SWI9X15C_05.05.58.00 r27038 carmd-fwbuild1 2015/03/04 21:30:23'>, 'Serial': <'356853052645654'>, 'Interfaces': <['org.ofono.SmartMessaging', 'org.ofono.PushNotification', 'org.ofono.MessageManager', 'org.ofono.RadioSettings', 'org.ofono.AllowedAccessPoints', 'org.ofono.SimManager', 'org.ofono.LocationReporting', 'org.ofono.VoiceCallManager']>, 'Features': <['sms', 'rat', 'sim', 'gps']>, 'Type': <'hardware'>},)

/gobi_3
({'Online': <false>, 'Powered': <true>, 'Lockdown': <false>, 'Emergency': <false>, 'Manufacturer': <'Quectel'>, 'Model': <'EC20'>, 'Revision': <'EC20EQAR02A05E2G  1  [Mar 14 2016 19:33:01]'>, 'Serial': <'20120822'>, 'Interfaces': <['org.ofono.SmartMessaging', 'org.ofono.PushNotification', 'org.ofono.MessageManager', 'org.ofono.RadioSettings', 'org.ofono.AllowedAccessPoints', 'org.ofono.SimManager', 'org.ofono.LocationReporting', 'org.ofono.VoiceCallManager']>, 'Features': <['sms', 'rat', 'sim', 'gps']>, 'Type': <'hardware'>},)
root@apu-roh:~# for m in /gobi_0 /gobi_1 /sierra_2 /gobi_3 ; do echo; echo; echo $m ; mdbus2 -s org.ofono $m org.ofono.Modem.SetProperty Online true; done

/gobi_0
()

/gobi_1
[ERR]: GDBus.Error:org.ofono.Error.Failed: Operation failed

/sierra_2
()

/gobi_3
()
root@apu-roh:~# for m in /gobi_0 /gobi_1 /sierra_2 /gobi_3 ; do echo; echo; echo $m ; mdbus2 -s org.ofono $m; done

/gobi_0
[METHOD]   org.freedesktop.DBus.Introspectable.Introspect() -> (s:xml)
[METHOD]   org.ofono.Modem.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.Modem.SetProperty(s:property, v:value) -> ()
[SIGNAL]   org.ofono.Modem.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.VoiceCallManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.VoiceCallManager.Dial(s:number, s:hide_callerid) -> (o:path)
[METHOD]   org.ofono.VoiceCallManager.Transfer() -> ()
[METHOD]   org.ofono.VoiceCallManager.SwapCalls() -> ()
[METHOD]   org.ofono.VoiceCallManager.ReleaseAndAnswer() -> ()
[METHOD]   org.ofono.VoiceCallManager.ReleaseAndSwap() -> ()
[METHOD]   org.ofono.VoiceCallManager.HoldAndAnswer() -> ()
[METHOD]   org.ofono.VoiceCallManager.HangupAll() -> ()
[METHOD]   org.ofono.VoiceCallManager.PrivateChat(o:call) -> (ao:calls)
[METHOD]   org.ofono.VoiceCallManager.CreateMultiparty() -> (ao:calls)
[METHOD]   org.ofono.VoiceCallManager.HangupMultiparty() -> ()
[METHOD]   org.ofono.VoiceCallManager.SendTones(s:SendTones) -> ()
[METHOD]   org.ofono.VoiceCallManager.GetCalls() -> (a(oa{sv}):calls_with_properties)
[SIGNAL]   org.ofono.VoiceCallManager.Forwarded(s:type)
[SIGNAL]   org.ofono.VoiceCallManager.BarringActive(s:type)
[SIGNAL]   org.ofono.VoiceCallManager.PropertyChanged(s:name, v:value)
[SIGNAL]   org.ofono.VoiceCallManager.CallAdded(o:path, a{sv}:properties)
[SIGNAL]   org.ofono.VoiceCallManager.CallRemoved(o:path)
[METHOD]   org.ofono.LocationReporting.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.LocationReporting.Request() -> (h:fd)
[METHOD]   org.ofono.LocationReporting.Release() -> ()
[SIGNAL]   org.ofono.LocationReporting.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.SimManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.SimManager.SetProperty(s:property, v:value) -> ()
[METHOD]   org.ofono.SimManager.ChangePin(s:type, s:oldpin, s:newpin) -> ()
[METHOD]   org.ofono.SimManager.EnterPin(s:type, s:pin) -> ()
[METHOD]   org.ofono.SimManager.ResetPin(s:type, s:puk, s:newpin) -> ()
[METHOD]   org.ofono.SimManager.LockPin(s:type, s:pin) -> ()
[METHOD]   org.ofono.SimManager.UnlockPin(s:type, s:pin) -> ()
[METHOD]   org.ofono.SimManager.GetIcon(y:id) -> (ay:icon)
[SIGNAL]   org.ofono.SimManager.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.AllowedAccessPoints.GetAllowedAccessPoints() -> (as:apnlist)
[METHOD]   org.ofono.RadioSettings.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.RadioSettings.SetProperty(s:property, v:value) -> ()
[SIGNAL]   org.ofono.RadioSettings.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.MessageManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.MessageManager.SetProperty(s:property, v:value) -> ()
[METHOD]   org.ofono.MessageManager.SendMessage(s:to, s:text) -> (o:path)
[METHOD]   org.ofono.MessageManager.GetMessages() -> (a(oa{sv}):messages)
[SIGNAL]   org.ofono.MessageManager.PropertyChanged(s:name, v:value)
[SIGNAL]   org.ofono.MessageManager.IncomingMessage(s:message, a{sv}:info)
[SIGNAL]   org.ofono.MessageManager.ImmediateMessage(s:message, a{sv}:info)
[SIGNAL]   org.ofono.MessageManager.MessageAdded(o:path, a{sv}:properties)
[SIGNAL]   org.ofono.MessageManager.MessageRemoved(o:path)
[METHOD]   org.ofono.PushNotification.RegisterAgent(o:path) -> ()
[METHOD]   org.ofono.PushNotification.UnregisterAgent(o:path) -> ()
[METHOD]   org.ofono.SmartMessaging.RegisterAgent(o:path) -> ()
[METHOD]   org.ofono.SmartMessaging.UnregisterAgent(o:path) -> ()
[METHOD]   org.ofono.SmartMessaging.SendBusinessCard(s:to, ay:card) -> (o:path)
[METHOD]   org.ofono.SmartMessaging.SendAppointment(s:to, ay:appointment) -> (o:path)
[METHOD]   org.ofono.SupplementaryServices.Initiate(s:command) -> (s:result_name, v:value)
[METHOD]   org.ofono.SupplementaryServices.Respond(s:reply) -> (s:result)
[METHOD]   org.ofono.SupplementaryServices.Cancel() -> ()
[METHOD]   org.ofono.SupplementaryServices.GetProperties() -> (a{sv}:properties)
[SIGNAL]   org.ofono.SupplementaryServices.NotificationReceived(s:message)
[SIGNAL]   org.ofono.SupplementaryServices.RequestReceived(s:message)
[SIGNAL]   org.ofono.SupplementaryServices.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.ConnectionManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.ConnectionManager.SetProperty(s:property, v:value) -> ()
[METHOD]   org.ofono.ConnectionManager.AddContext(s:type) -> (o:path)
[METHOD]   org.ofono.ConnectionManager.RemoveContext(o:path) -> ()
[METHOD]   org.ofono.ConnectionManager.DeactivateAll() -> ()
[METHOD]   org.ofono.ConnectionManager.GetContexts() -> (a(oa{sv}):contexts_with_properties)
[METHOD]   org.ofono.ConnectionManager.ResetContexts() -> ()
[SIGNAL]   org.ofono.ConnectionManager.PropertyChanged(s:name, v:value)
[SIGNAL]   org.ofono.ConnectionManager.ContextAdded(o:path, a{sv}:properties)
[SIGNAL]   org.ofono.ConnectionManager.ContextRemoved(o:path)
[METHOD]   org.ofono.NetworkRegistration.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.NetworkRegistration.Register() -> ()
[METHOD]   org.ofono.NetworkRegistration.GetOperators() -> (a(oa{sv}):operators_with_properties)
[METHOD]   org.ofono.NetworkRegistration.Scan() -> (a(oa{sv}):operators_with_properties)
[SIGNAL]   org.ofono.NetworkRegistration.PropertyChanged(s:name, v:value)

/gobi_1
[METHOD]   org.freedesktop.DBus.Introspectable.Introspect() -> (s:xml)
[METHOD]   org.ofono.Modem.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.Modem.SetProperty(s:property, v:value) -> ()
[SIGNAL]   org.ofono.Modem.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.AllowedAccessPoints.GetAllowedAccessPoints() -> (as:apnlist)
[METHOD]   org.ofono.LocationReporting.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.LocationReporting.Request() -> (h:fd)
[METHOD]   org.ofono.LocationReporting.Release() -> ()
[SIGNAL]   org.ofono.LocationReporting.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.SimManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.SimManager.SetProperty(s:property, v:value) -> ()
[METHOD]   org.ofono.SimManager.ChangePin(s:type, s:oldpin, s:newpin) -> ()
[METHOD]   org.ofono.SimManager.EnterPin(s:type, s:pin) -> ()
[METHOD]   org.ofono.SimManager.ResetPin(s:type, s:puk, s:newpin) -> ()
[METHOD]   org.ofono.SimManager.LockPin(s:type, s:pin) -> ()
[METHOD]   org.ofono.SimManager.UnlockPin(s:type, s:pin) -> ()
[METHOD]   org.ofono.SimManager.GetIcon(y:id) -> (ay:icon)
[SIGNAL]   org.ofono.SimManager.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.RadioSettings.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.RadioSettings.SetProperty(s:property, v:value) -> ()
[SIGNAL]   org.ofono.RadioSettings.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.MessageManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.MessageManager.SetProperty(s:property, v:value) -> ()
[METHOD]   org.ofono.MessageManager.SendMessage(s:to, s:text) -> (o:path)
[METHOD]   org.ofono.MessageManager.GetMessages() -> (a(oa{sv}):messages)
[SIGNAL]   org.ofono.MessageManager.PropertyChanged(s:name, v:value)
[SIGNAL]   org.ofono.MessageManager.IncomingMessage(s:message, a{sv}:info)
[SIGNAL]   org.ofono.MessageManager.ImmediateMessage(s:message, a{sv}:info)
[SIGNAL]   org.ofono.MessageManager.MessageAdded(o:path, a{sv}:properties)
[SIGNAL]   org.ofono.MessageManager.MessageRemoved(o:path)
[METHOD]   org.ofono.PushNotification.RegisterAgent(o:path) -> ()
[METHOD]   org.ofono.PushNotification.UnregisterAgent(o:path) -> ()
[METHOD]   org.ofono.SmartMessaging.RegisterAgent(o:path) -> ()
[METHOD]   org.ofono.SmartMessaging.UnregisterAgent(o:path) -> ()
[METHOD]   org.ofono.SmartMessaging.SendBusinessCard(s:to, ay:card) -> (o:path)
[METHOD]   org.ofono.SmartMessaging.SendAppointment(s:to, ay:appointment) -> (o:path)

/sierra_2
[METHOD]   org.freedesktop.DBus.Introspectable.Introspect() -> (s:xml)
[METHOD]   org.ofono.Modem.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.Modem.SetProperty(s:property, v:value) -> ()
[SIGNAL]   org.ofono.Modem.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.VoiceCallManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.VoiceCallManager.Dial(s:number, s:hide_callerid) -> (o:path)
[METHOD]   org.ofono.VoiceCallManager.Transfer() -> ()
[METHOD]   org.ofono.VoiceCallManager.SwapCalls() -> ()
[METHOD]   org.ofono.VoiceCallManager.ReleaseAndAnswer() -> ()
[METHOD]   org.ofono.VoiceCallManager.ReleaseAndSwap() -> ()
[METHOD]   org.ofono.VoiceCallManager.HoldAndAnswer() -> ()
[METHOD]   org.ofono.VoiceCallManager.HangupAll() -> ()
[METHOD]   org.ofono.VoiceCallManager.PrivateChat(o:call) -> (ao:calls)
[METHOD]   org.ofono.VoiceCallManager.CreateMultiparty() -> (ao:calls)
[METHOD]   org.ofono.VoiceCallManager.HangupMultiparty() -> ()
[METHOD]   org.ofono.VoiceCallManager.SendTones(s:SendTones) -> ()
[METHOD]   org.ofono.VoiceCallManager.GetCalls() -> (a(oa{sv}):calls_with_properties)
[SIGNAL]   org.ofono.VoiceCallManager.Forwarded(s:type)
[SIGNAL]   org.ofono.VoiceCallManager.BarringActive(s:type)
[SIGNAL]   org.ofono.VoiceCallManager.PropertyChanged(s:name, v:value)
[SIGNAL]   org.ofono.VoiceCallManager.CallAdded(o:path, a{sv}:properties)
[SIGNAL]   org.ofono.VoiceCallManager.CallRemoved(o:path)
[METHOD]   org.ofono.LocationReporting.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.LocationReporting.Request() -> (h:fd)
[METHOD]   org.ofono.LocationReporting.Release() -> ()
[SIGNAL]   org.ofono.LocationReporting.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.SimManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.SimManager.SetProperty(s:property, v:value) -> ()
[METHOD]   org.ofono.SimManager.ChangePin(s:type, s:oldpin, s:newpin) -> ()
[METHOD]   org.ofono.SimManager.EnterPin(s:type, s:pin) -> ()
[METHOD]   org.ofono.SimManager.ResetPin(s:type, s:puk, s:newpin) -> ()
[METHOD]   org.ofono.SimManager.LockPin(s:type, s:pin) -> ()
[METHOD]   org.ofono.SimManager.UnlockPin(s:type, s:pin) -> ()
[METHOD]   org.ofono.SimManager.GetIcon(y:id) -> (ay:icon)
[SIGNAL]   org.ofono.SimManager.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.AllowedAccessPoints.GetAllowedAccessPoints() -> (as:apnlist)
[METHOD]   org.ofono.RadioSettings.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.RadioSettings.SetProperty(s:property, v:value) -> ()
[SIGNAL]   org.ofono.RadioSettings.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.MessageManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.MessageManager.SetProperty(s:property, v:value) -> ()
[METHOD]   org.ofono.MessageManager.SendMessage(s:to, s:text) -> (o:path)
[METHOD]   org.ofono.MessageManager.GetMessages() -> (a(oa{sv}):messages)
[SIGNAL]   org.ofono.MessageManager.PropertyChanged(s:name, v:value)
[SIGNAL]   org.ofono.MessageManager.IncomingMessage(s:message, a{sv}:info)
[SIGNAL]   org.ofono.MessageManager.ImmediateMessage(s:message, a{sv}:info)
[SIGNAL]   org.ofono.MessageManager.MessageAdded(o:path, a{sv}:properties)
[SIGNAL]   org.ofono.MessageManager.MessageRemoved(o:path)
[METHOD]   org.ofono.PushNotification.RegisterAgent(o:path) -> ()
[METHOD]   org.ofono.PushNotification.UnregisterAgent(o:path) -> ()
[METHOD]   org.ofono.SmartMessaging.RegisterAgent(o:path) -> ()
[METHOD]   org.ofono.SmartMessaging.UnregisterAgent(o:path) -> ()
[METHOD]   org.ofono.SmartMessaging.SendBusinessCard(s:to, ay:card) -> (o:path)
[METHOD]   org.ofono.SmartMessaging.SendAppointment(s:to, ay:appointment) -> (o:path)
[METHOD]   org.ofono.SupplementaryServices.Initiate(s:command) -> (s:result_name, v:value)
[METHOD]   org.ofono.SupplementaryServices.Respond(s:reply) -> (s:result)
[METHOD]   org.ofono.SupplementaryServices.Cancel() -> ()
[METHOD]   org.ofono.SupplementaryServices.GetProperties() -> (a{sv}:properties)
[SIGNAL]   org.ofono.SupplementaryServices.NotificationReceived(s:message)
[SIGNAL]   org.ofono.SupplementaryServices.RequestReceived(s:message)
[SIGNAL]   org.ofono.SupplementaryServices.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.ConnectionManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.ConnectionManager.SetProperty(s:property, v:value) -> ()
[METHOD]   org.ofono.ConnectionManager.AddContext(s:type) -> (o:path)
[METHOD]   org.ofono.ConnectionManager.RemoveContext(o:path) -> ()
[METHOD]   org.ofono.ConnectionManager.DeactivateAll() -> ()
[METHOD]   org.ofono.ConnectionManager.GetContexts() -> (a(oa{sv}):contexts_with_properties)
[METHOD]   org.ofono.ConnectionManager.ResetContexts() -> ()
[SIGNAL]   org.ofono.ConnectionManager.PropertyChanged(s:name, v:value)
[SIGNAL]   org.ofono.ConnectionManager.ContextAdded(o:path, a{sv}:properties)
[SIGNAL]   org.ofono.ConnectionManager.ContextRemoved(o:path)
[METHOD]   org.ofono.NetworkRegistration.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.NetworkRegistration.Register() -> ()
[METHOD]   org.ofono.NetworkRegistration.GetOperators() -> (a(oa{sv}):operators_with_properties)
[METHOD]   org.ofono.NetworkRegistration.Scan() -> (a(oa{sv}):operators_with_properties)
[SIGNAL]   org.ofono.NetworkRegistration.PropertyChanged(s:name, v:value)

/gobi_3
[METHOD]   org.freedesktop.DBus.Introspectable.Introspect() -> (s:xml)
[METHOD]   org.ofono.Modem.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.Modem.SetProperty(s:property, v:value) -> ()
[SIGNAL]   org.ofono.Modem.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.VoiceCallManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.VoiceCallManager.Dial(s:number, s:hide_callerid) -> (o:path)
[METHOD]   org.ofono.VoiceCallManager.Transfer() -> ()
[METHOD]   org.ofono.VoiceCallManager.SwapCalls() -> ()
[METHOD]   org.ofono.VoiceCallManager.ReleaseAndAnswer() -> ()
[METHOD]   org.ofono.VoiceCallManager.ReleaseAndSwap() -> ()
[METHOD]   org.ofono.VoiceCallManager.HoldAndAnswer() -> ()
[METHOD]   org.ofono.VoiceCallManager.HangupAll() -> ()
[METHOD]   org.ofono.VoiceCallManager.PrivateChat(o:call) -> (ao:calls)
[METHOD]   org.ofono.VoiceCallManager.CreateMultiparty() -> (ao:calls)
[METHOD]   org.ofono.VoiceCallManager.HangupMultiparty() -> ()
[METHOD]   org.ofono.VoiceCallManager.SendTones(s:SendTones) -> ()
[METHOD]   org.ofono.VoiceCallManager.GetCalls() -> (a(oa{sv}):calls_with_properties)
[SIGNAL]   org.ofono.VoiceCallManager.Forwarded(s:type)
[SIGNAL]   org.ofono.VoiceCallManager.BarringActive(s:type)
[SIGNAL]   org.ofono.VoiceCallManager.PropertyChanged(s:name, v:value)
[SIGNAL]   org.ofono.VoiceCallManager.CallAdded(o:path, a{sv}:properties)
[SIGNAL]   org.ofono.VoiceCallManager.CallRemoved(o:path)
[METHOD]   org.ofono.LocationReporting.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.LocationReporting.Request() -> (h:fd)
[METHOD]   org.ofono.LocationReporting.Release() -> ()
[SIGNAL]   org.ofono.LocationReporting.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.SimManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.SimManager.SetProperty(s:property, v:value) -> ()
[METHOD]   org.ofono.SimManager.ChangePin(s:type, s:oldpin, s:newpin) -> ()
[METHOD]   org.ofono.SimManager.EnterPin(s:type, s:pin) -> ()
[METHOD]   org.ofono.SimManager.ResetPin(s:type, s:puk, s:newpin) -> ()
[METHOD]   org.ofono.SimManager.LockPin(s:type, s:pin) -> ()
[METHOD]   org.ofono.SimManager.UnlockPin(s:type, s:pin) -> ()
[METHOD]   org.ofono.SimManager.GetIcon(y:id) -> (ay:icon)
[SIGNAL]   org.ofono.SimManager.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.AllowedAccessPoints.GetAllowedAccessPoints() -> (as:apnlist)
[METHOD]   org.ofono.RadioSettings.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.RadioSettings.SetProperty(s:property, v:value) -> ()
[SIGNAL]   org.ofono.RadioSettings.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.MessageManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.MessageManager.SetProperty(s:property, v:value) -> ()
[METHOD]   org.ofono.MessageManager.SendMessage(s:to, s:text) -> (o:path)
[METHOD]   org.ofono.MessageManager.GetMessages() -> (a(oa{sv}):messages)
[SIGNAL]   org.ofono.MessageManager.PropertyChanged(s:name, v:value)
[SIGNAL]   org.ofono.MessageManager.IncomingMessage(s:message, a{sv}:info)
[SIGNAL]   org.ofono.MessageManager.ImmediateMessage(s:message, a{sv}:info)
[SIGNAL]   org.ofono.MessageManager.MessageAdded(o:path, a{sv}:properties)
[SIGNAL]   org.ofono.MessageManager.MessageRemoved(o:path)
[METHOD]   org.ofono.PushNotification.RegisterAgent(o:path) -> ()
[METHOD]   org.ofono.PushNotification.UnregisterAgent(o:path) -> ()
[METHOD]   org.ofono.SmartMessaging.RegisterAgent(o:path) -> ()
[METHOD]   org.ofono.SmartMessaging.UnregisterAgent(o:path) -> ()
[METHOD]   org.ofono.SmartMessaging.SendBusinessCard(s:to, ay:card) -> (o:path)
[METHOD]   org.ofono.SmartMessaging.SendAppointment(s:to, ay:appointment) -> (o:path)
[METHOD]   org.ofono.SupplementaryServices.Initiate(s:command) -> (s:result_name, v:value)
[METHOD]   org.ofono.SupplementaryServices.Respond(s:reply) -> (s:result)
[METHOD]   org.ofono.SupplementaryServices.Cancel() -> ()
[METHOD]   org.ofono.SupplementaryServices.GetProperties() -> (a{sv}:properties)
[SIGNAL]   org.ofono.SupplementaryServices.NotificationReceived(s:message)
[SIGNAL]   org.ofono.SupplementaryServices.RequestReceived(s:message)
[SIGNAL]   org.ofono.SupplementaryServices.PropertyChanged(s:name, v:value)
[METHOD]   org.ofono.ConnectionManager.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.ConnectionManager.SetProperty(s:property, v:value) -> ()
[METHOD]   org.ofono.ConnectionManager.AddContext(s:type) -> (o:path)
[METHOD]   org.ofono.ConnectionManager.RemoveContext(o:path) -> ()
[METHOD]   org.ofono.ConnectionManager.DeactivateAll() -> ()
[METHOD]   org.ofono.ConnectionManager.GetContexts() -> (a(oa{sv}):contexts_with_properties)
[METHOD]   org.ofono.ConnectionManager.ResetContexts() -> ()
[SIGNAL]   org.ofono.ConnectionManager.PropertyChanged(s:name, v:value)
[SIGNAL]   org.ofono.ConnectionManager.ContextAdded(o:path, a{sv}:properties)
[SIGNAL]   org.ofono.ConnectionManager.ContextRemoved(o:path)
[METHOD]   org.ofono.NetworkRegistration.GetProperties() -> (a{sv}:properties)
[METHOD]   org.ofono.NetworkRegistration.Register() -> ()
[METHOD]   org.ofono.NetworkRegistration.GetOperators() -> (a(oa{sv}):operators_with_properties)
[METHOD]   org.ofono.NetworkRegistration.Scan() -> (a(oa{sv}):operators_with_properties)
[SIGNAL]   org.ofono.NetworkRegistration.PropertyChanged(s:name, v:value)
root@apu-roh:~# for m in /gobi_0 /gobi_1 /sierra_2 /gobi_3 ; do echo; echo; echo $m ; mdbus2 -s org.ofono $m org.ofono.SimManager.GetProperties; done

/gobi_0
({'Present': <true>, 'CardIdentifier': <'8988211000000090301'>, 'SubscriberIdentity': <'901700000009030'>, 'FixedDialing': <false>, 'BarredDialing': <false>, 'MobileCountryCode': <'901'>, 'MobileNetworkCode': <'70'>, 'SubscriberNumbers': <@as []>, 'LockedPins': <@as []>, 'PinRequired': <'none'>, 'Retries': <{'pin': byte 0x03, 'phone': 0x00, 'firstphone': 0x00, 'pin2': 0x03, 'network': 0x49, 'netsub': 0x00, 'service': 0x2f, 'corp': 0x00, 'puk': 0x0a, 'firstphonepuk': 0x2b, 'puk2': 0x0a, 'networkpuk': 0x00, 'netsubpuk': 0x08, 'servicepuk': 0x00, 'corppuk': 0x20}>},)

/gobi_1
({'Present': <true>, 'CardIdentifier': <'8988211000000090319'>, 'SubscriberIdentity': <'901700000009031'>, 'FixedDialing': <false>, 'BarredDialing': <false>, 'SubscriberNumbers': <@as []>, 'LockedPins': <@as []>, 'PinRequired': <'none'>, 'Retries': <{'pin': byte 0x03, 'pin2': 0x03, 'puk': 0x0a, 'puk2': 0x0a}>},)

/sierra_2
({'Present': <true>, 'CardIdentifier': <'8988211000000090293'>, 'SubscriberIdentity': <'901700000009029'>, 'FixedDialing': <false>, 'BarredDialing': <false>, 'MobileCountryCode': <'901'>, 'MobileNetworkCode': <'70'>, 'SubscriberNumbers': <@as []>, 'LockedPins': <@as []>, 'PinRequired': <'none'>, 'Retries': <{'pin': byte 0x03, 'phone': 0x00, 'firstphone': 0x00, 'pin2': 0x03, 'network': 0x49, 'netsub': 0x00, 'service': 0x2f, 'corp': 0x00, 'puk': 0x0a, 'firstphonepuk': 0x2b, 'puk2': 0x0a, 'networkpuk': 0x00, 'netsubpuk': 0x08, 'servicepuk': 0x00, 'corppuk': 0x20}>},)

/gobi_3
({'Present': <true>, 'CardIdentifier': <'8988211000000090327'>, 'SubscriberIdentity': <'901700000009032'>, 'FixedDialing': <false>, 'BarredDialing': <false>, 'MobileCountryCode': <'901'>, 'MobileNetworkCode': <'70'>, 'SubscriberNumbers': <@as []>, 'LockedPins': <@as []>, 'PinRequired': <'none'>, 'Retries': <{'pin': byte 0x03, 'phone': 0x00, 'firstphone': 0x00, 'pin2': 0x03, 'network': 0x49, 'netsub': 0x00, 'service': 0x2f, 'corp': 0x00, 'puk': 0x0a, 'firstphonepuk': 0x2b, 'puk2': 0x0a, 'networkpuk': 0x00, 'netsubpuk': 0x08, 'servicepuk': 0x00, 'corppuk': 0x20}>},)
root@apu-roh:~# 
root@apu-roh:~# 
root@apu-roh:~# 
root@apu-roh:~# for m in /gobi_0 /gobi_1 /sierra_2 /gobi_3 ; do echo; echo; echo $m ; mdbus2 -s org.ofono $m org.ofono.MessageManager.SendMessage '45678' "test sms from $m"; done

/gobi_0
('/gobi_0/message_2FAB679E0E1E6782DC54DAFF4656889720D9F1DB',)

/gobi_1
('/gobi_1/message_2A49A61594912144F81C1BD6824A65470CCE96BB',)

/sierra_2
('/sierra_2/message_048211324677D442638A074BE90CC21F456BA1FB',)

/gobi_3
('/gobi_3/message_CA986B2EB97ECF8624365A0DC541D23449D864B3',)
root@apu-roh:~# for m in /gobi_0 /gobi_1 /sierra_2 /gobi_3 ; do echo; echo; echo $m ; mdbus2 -s org.ofono $m org.ofono.MessageManager.GetMessages; done

/gobi_0
([],)

/gobi_1
([('/gobi_1/message_2A49A61594912144F81C1BD6824A65470CCE96BB', {'State': <'pending'>}), ('/gobi_1/message_56B7C7DA20E3E7EF87343D81904712A6587CC48A', {'State': <'pending'>})],)

/sierra_2
([],)

/gobi_3
([],)
root@apu-roh:~# for m in /gobi_0 /gobi_1 /sierra_2 /gobi_3 ; do echo; echo; echo $m ; mdbus2 -s org.ofono $m org.ofono.MessageManager.SendMessage '45678' "test sms from $m"; done

/gobi_0
('/gobi_0/message_760284EBD1F631076ECBCE70C0947A2A1E6B53A7',)

/gobi_1
('/gobi_1/message_75D21162B26B37D3AF8682893AD7BA72DF76941E',)

/sierra_2
('/sierra_2/message_FE43C86DDE6F5D6C594A0BEB28D849740E9830A5',)

/gobi_3
('/gobi_3/message_864B19DE5C7A454347DDA51EE249C2409B161523',)
root@apu-roh:~# for m in /gobi_0 /gobi_1 /sierra_2 /gobi_3 ; do echo; echo; echo $m ; mdbus2 -s org.ofono $m org.ofono.MessageManager.SendMessage '39631' "test sms from $m"; done

/gobi_0
('/gobi_0/message_9EAA27649CB131ABE1BF1D75588F63D899417C54',)

/gobi_1
('/gobi_1/message_D9897F38339FF28B1E1752560B8D9FC98468D88F',)

/sierra_2
('/sierra_2/message_49AB02CE99B57F169FECED5450A9A3BA31DB81E7',)

/gobi_3
('/gobi_3/message_1868668A7578AC22A0FBBCEEA627E0C9736DCAD9',)
root@apu-roh:~# for m in /gobi_0 /gobi_1 /sierra_2 /gobi_3 ; do echo; echo; echo $m ; mdbus2 -s org.ofono $m org.ofono.MessageManager.SendMessage '22771' "test sms from $m"; done

/gobi_0
('/gobi_0/message_DAEAAC1A870FDEAFDDC682D4B4B0D29BB86F3DD7',)

/gobi_1
('/gobi_1/message_448EBA7C1E3690ECE9B4D4B7532119657A6B3A75',)

/sierra_2
('/sierra_2/message_B2C828706B66149D5CFC3A3D7580B88160DB6D44',)

/gobi_3
('/gobi_3/message_052206672FB1F7F88AE327F5A17F6DEBF87557B5',)
root@apu-roh:~# for m in /gobi_0 /gobi_1 /sierra_2 /gobi_3 ; do echo; echo; echo $m ; mdbus2 -s org.ofono $m org.ofono.MessageManager.SendMessage '48292' "test sms from $m"; done

/gobi_0
('/gobi_0/message_57ED71AEE7430D176CA17112807451B0473EA892',)

/gobi_1
('/gobi_1/message_2F6EB331F57B1921C969F26A0744C09B8F401675',)

/sierra_2
('/sierra_2/message_93A9C03568D000ED8D7F17D9DA26E0F8BF6F3955',)

/gobi_3
('/gobi_3/message_D78F919D5F13E8A78ABC5E6C140B1A96D719039D',)

SMS received:

root@apu-roh:~# mdbus2 -l -s org.ofono /gobi_3 
[SIGNAL] org.ofono.MessageManager.MessageAdded  /gobi_3  :1.99
('/gobi_3/message_864B19DE5C7A454347DDA51EE249C2409B161523', {'State': <'pending'>})
[SIGNAL] org.ofono.MessageManager.IncomingMessage  /gobi_3  :1.99
('test sms from /sierra_2', {'LocalSentTime': <'2017-04-25T16:58:01+0200'>, 'SentTime': <'2017-04-25T14:58:01+0000'>, 'Sender': <'39631'>})
[SIGNAL] org.ofono.MessageManager.MessageRemoved  /gobi_3  :1.99
('/gobi_3/message_864B19DE5C7A454347DDA51EE249C2409B161523',)
^C
root@apu-roh:~# mdbus2 -l -s org.ofono /sierra_2
[SIGNAL] org.ofono.MessageManager.MessageAdded  /sierra_2  :1.99
('/sierra_2/message_49AB02CE99B57F169FECED5450A9A3BA31DB81E7', {'State': <'pending'>})
[SIGNAL] org.ofono.MessageManager.MessageRemoved  /sierra_2  :1.99
('/sierra_2/message_49AB02CE99B57F169FECED5450A9A3BA31DB81E7',)
[SIGNAL] org.ofono.MessageManager.IncomingMessage  /sierra_2  :1.99
('test sms from /sierra_2', {'LocalSentTime': <'2017-04-25T16:59:38+0200'>, 'SentTime': <'2017-04-25T14:59:38+0000'>, 'Sender': <'39631'>})
^C
root@apu-roh:~# mdbus2 -l -s org.ofono /gobi_1
[SIGNAL] org.ofono.MessageManager.MessageAdded  /gobi_1  :1.99
('/gobi_1/message_448EBA7C1E3690ECE9B4D4B7532119657A6B3A75', {'State': <'pending'>})
^C
root@apu-roh:~# mdbus2 -l -s org.ofono /gobi_0
[SIGNAL] org.ofono.MessageManager.MessageAdded  /gobi_0  :1.99
('/gobi_0/message_57ED71AEE7430D176CA17112807451B0473EA892', {'State': <'pending'>})
[SIGNAL] org.ofono.MessageManager.IncomingMessage  /gobi_0  :1.99
('test sms from /sierra_2', {'LocalSentTime': <'2017-04-25T17:01:31+0200'>, 'SentTime': <'2017-04-25T15:01:31+0000'>, 'Sender': <'39631'>})
[SIGNAL] org.ofono.MessageManager.MessageRemoved  /gobi_0  :1.99
('/gobi_0/message_57ED71AEE7430D176CA17112807451B0473EA892',)

#3 Updated by neels 5 months ago

corresponding NITB log

20170425165054343 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=1 as SDCCH
20170425165054343 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=1) Activating ARFCN(868) SS(1) lctype SDCCH r=LOCATION_UPDATE ra=0x0f ta=0
20170425165054343 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425165054343 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state NONE -> ACTIVATION REQUESTED
20170425165054384 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=1) CHANNEL ACTIVATE ACK
20170425165054384 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVATION REQUESTED -> ACTIVE
20170425165055181 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 ESTABLISH INDICATION
20170425165055181 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425165055181 <0002> gsm_04_08.c:1407 LOCATION UPDATING REQUEST: MI(TMSI)=4181543449 type=IMSI ATTACH 
20170425165055184 <000d> db.c:915 Found Subscriber: ID 3, IMSI 901700000009032, NAME '', TMSI f93d4a19, EXTEN '45678', LAC 0, AUTH 1
20170425165055186 <0001> gsm_04_08.c:149 (bts 0 trx 0 ts 0 pd 05) Sending 0x18 to MS.
20170425165055352 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=2 as SDCCH
20170425165055352 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=2) Activating ARFCN(868) SS(2) lctype SDCCH r=LOCATION_UPDATE ra=0x08 ta=0
20170425165055352 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425165055352 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=2) state NONE -> ACTIVATION REQUESTED
20170425165055393 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=2) CHANNEL ACTIVATE ACK
20170425165055393 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=2) state ACTIVATION REQUESTED -> ACTIVE
20170425165055544 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=3 as SDCCH
20170425165055544 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=3) Activating ARFCN(868) SS(3) lctype SDCCH r=LOCATION_UPDATE ra=0x04 ta=0
20170425165055544 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425165055544 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=3) state NONE -> ACTIVATION REQUESTED
20170425165055584 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=3) CHANNEL ACTIVATE ACK
20170425165055584 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=3) state ACTIVATION REQUESTED -> ACTIVE
20170425165055656 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 DATA INDICATION
20170425165055656 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425165055656 <0002> gsm_04_08.c:572 IDENTITY RESPONSE: MI(IMEI)=868323024275960
20170425165055706 <000d> db.c:1422 Updated EquipmentWatch: ID 1, IMSI 901700000009032, IMEI 868323024275960
20170425165055706 <000d> db.c:1156 Sync Equipment IMEI=868323024275960, classmark1=30
20170425165055724 <000d> db.c:1251 Allocated TMSI 2935350627 for IMSI 901700000009032.
20170425165055742 <0002> gsm_04_08.c:529 -> LOCATION UPDATE ACCEPT
20170425165055742 <0001> gsm_04_08.c:149 (bts 0 trx 0 ts 0 pd 05) Sending 0x02 to MS.
20170425165055742 <0002> gsm_04_08.c:892 -> MM INFO
20170425165055742 <0001> gsm_04_08.c:149 (bts 0 trx 0 ts 0 pd 05) Sending 0x32 to MS.
20170425165055743 <0002> gsm_subscriber.c:341 Subscriber 901700000009032 ATTACHED LAC=23
20170425165055771 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=2) SAPI=0 ESTABLISH INDICATION
20170425165055771 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425165055771 <0002> gsm_04_08.c:1407 LOCATION UPDATING REQUEST: MI(TMSI)=3483336878 type=IMSI ATTACH 
20170425165055774 <000d> db.c:915 Found Subscriber: ID 6, IMSI 901700000009029, NAME '', TMSI cf9f80ae, EXTEN '39631', LAC 0, AUTH 1
20170425165055776 <0001> gsm_04_08.c:149 (bts 0 trx 0 ts 0 pd 05) Sending 0x18 to MS.
20170425165055931 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=3) SAPI=0 ESTABLISH INDICATION
20170425165055931 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425165055931 <0002> gsm_04_08.c:1407 LOCATION UPDATING REQUEST: MI(TMSI)=884560976 type=IMSI ATTACH 
20170425165055934 <000d> db.c:915 Found Subscriber: ID 4, IMSI 901700000009030, NAME '', TMSI 34b95450, EXTEN '48292', LAC 0, AUTH 1
20170425165055936 <0001> gsm_04_08.c:149 (bts 0 trx 0 ts 0 pd 05) Sending 0x18 to MS.
20170425165056130 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 DATA INDICATION
20170425165056130 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425165056130 <0002> gsm_04_08.c:1421 TMSI Reallocation Completed. Subscriber: 901700000009032
20170425165056130 <0002> gsm_04_08.c:328 Location Updating completed for 901700000009032
20170425165056130 <0000> chan_alloc.c:486 (bts=0,trx=0,ts=0,ss=1) starting release sequence
20170425165056130 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVE -> RELEASE REQUESTED
20170425165056130 <0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 1 Type: 1
20170425165056130 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=1) DEACTivate SACCH CMD
20170425165056162 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=2) SAPI=0 DATA INDICATION
20170425165056162 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425165056162 <0002> gsm_04_08.c:572 IDENTITY RESPONSE: MI(IMEI)=356853052645650
20170425165056208 <000d> db.c:1422 Updated EquipmentWatch: ID 5, IMSI 901700000009029, IMEI 356853052645650
20170425165056208 <000d> db.c:1156 Sync Equipment IMEI=356853052645650, classmark1=30, classmark2=30 58 a6 
20170425165056228 <000d> db.c:1251 Allocated TMSI 1577075595 for IMSI 901700000009029.
20170425165056246 <0002> gsm_04_08.c:529 -> LOCATION UPDATE ACCEPT
20170425165056246 <0001> gsm_04_08.c:149 (bts 0 trx 0 ts 0 pd 05) Sending 0x02 to MS.
20170425165056246 <0002> gsm_04_08.c:892 -> MM INFO
20170425165056246 <0001> gsm_04_08.c:149 (bts 0 trx 0 ts 0 pd 05) Sending 0x32 to MS.
20170425165056246 <0002> gsm_subscriber.c:341 Subscriber 901700000009029 ATTACHED LAC=23
20170425165056406 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=3) SAPI=0 DATA INDICATION
20170425165056406 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425165056406 <0002> gsm_04_08.c:572 IDENTITY RESPONSE: MI(IMEI)=868323024272130
20170425165056453 <000d> db.c:1422 Updated EquipmentWatch: ID 2, IMSI 901700000009030, IMEI 868323024272130
20170425165056453 <000d> db.c:1156 Sync Equipment IMEI=868323024272130, classmark1=30
20170425165056474 <000d> db.c:1251 Allocated TMSI 205914907 for IMSI 901700000009030.
20170425165056491 <0002> gsm_04_08.c:529 -> LOCATION UPDATE ACCEPT
20170425165056491 <0001> gsm_04_08.c:149 (bts 0 trx 0 ts 0 pd 05) Sending 0x02 to MS.
20170425165056492 <0002> gsm_04_08.c:892 -> MM INFO
20170425165056492 <0001> gsm_04_08.c:149 (bts 0 trx 0 ts 0 pd 05) Sending 0x32 to MS.
20170425165056492 <0002> gsm_subscriber.c:341 Subscriber 901700000009030 ATTACHED LAC=23
20170425165056627 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=2) SAPI=0 DATA INDICATION
20170425165056627 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425165056627 <0002> gsm_04_08.c:1421 TMSI Reallocation Completed. Subscriber: 901700000009029
20170425165056627 <0002> gsm_04_08.c:328 Location Updating completed for 901700000009029
20170425165056627 <0000> chan_alloc.c:486 (bts=0,trx=0,ts=0,ss=2) starting release sequence
20170425165056627 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=2) state ACTIVE -> RELEASE REQUESTED
20170425165056627 <0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 2 Type: 1
20170425165056627 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=2) DEACTivate SACCH CMD
20170425165056669 <0004> abis_rsl.c:1424 (bts=0,trx=0,ts=0,ss=2): MEAS RES for inactive channel
20170425165056879 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=3) SAPI=0 DATA INDICATION
20170425165056880 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425165056880 <0002> gsm_04_08.c:1421 TMSI Reallocation Completed. Subscriber: 901700000009030
20170425165056880 <0002> gsm_04_08.c:328 Location Updating completed for 901700000009030
20170425165056880 <0000> chan_alloc.c:486 (bts=0,trx=0,ts=0,ss=3) starting release sequence
20170425165056880 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=3) state ACTIVE -> RELEASE REQUESTED
20170425165056880 <0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 3 Type: 1
20170425165056880 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=3) DEACTivate SACCH CMD
20170425165057064 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 RELEASE INDICATION
20170425165057065 <0004> abis_rsl.c:1708 (bts=0,trx=0,ts=0,ss=1) T3111 expired: releasing RF Channel
20170425165057065 <0004> abis_rsl.c:859 (bts=0,trx=0,ts=0,ss=1) RF Channel Release
20170425165057097 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=1) RF CHANNEL RELEASE ACK
20170425165057097 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state RELEASE REQUESTED -> NONE
20170425165057563 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=2) SAPI=0 RELEASE INDICATION
20170425165057563 <0004> abis_rsl.c:1708 (bts=0,trx=0,ts=0,ss=2) T3111 expired: releasing RF Channel
20170425165057563 <0004> abis_rsl.c:859 (bts=0,trx=0,ts=0,ss=2) RF Channel Release
20170425165057600 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=2) RF CHANNEL RELEASE ACK
20170425165057600 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=2) state RELEASE REQUESTED -> NONE
20170425165057817 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=3) SAPI=0 RELEASE INDICATION
20170425165057817 <0004> abis_rsl.c:1708 (bts=0,trx=0,ts=0,ss=3) T3111 expired: releasing RF Channel
20170425165057817 <0004> abis_rsl.c:859 (bts=0,trx=0,ts=0,ss=3) RF Channel Release
20170425165057839 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=3) RF CHANNEL RELEASE ACK
20170425165057839 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=3) state RELEASE REQUESTED -> NONE

^[[A^[[A20170425165303126 <000d> db.c:915 Found Subscriber: ID 4, IMSI 901700000009030, NAME '', TMSI c46031b, EXTEN '48292', LAC 23, AUTH 1
20170425165346528 <000d> db.c:915 Found Subscriber: ID 5, IMSI 901700000009031, NAME '', TMSI ffffffff, EXTEN '22771', LAC 0, AUTH 1
20170425165349543 <000d> db.c:915 Found Subscriber: ID 6, IMSI 901700000009029, NAME '', TMSI 5e00438b, EXTEN '39631', LAC 23, AUTH 1
20170425165353007 <000d> db.c:915 Found Subscriber: ID 3, IMSI 901700000009032, NAME '', TMSI aef5e563, EXTEN '45678', LAC 23, AUTH 1

20170425165529011 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=1 as SDCCH
20170425165529011 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=1) Activating ARFCN(868) SS(1) lctype SDCCH r=OTHER ra=0x10 ta=0
20170425165529011 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425165529011 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state NONE -> ACTIVATION REQUESTED
20170425165529054 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=1) CHANNEL ACTIVATE ACK
20170425165529055 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVATION REQUESTED -> ACTIVE
20170425165529375 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 ESTABLISH INDICATION
20170425165529375 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425165529375 <0002> gsm_04_08.c:1016 <- CM SERVICE REQUEST serv_type=0x04 MI(TMSI)=1577075595
20170425165529378 <000d> db.c:915 Found Subscriber: ID 6, IMSI 901700000009029, NAME '', TMSI 5e00438b, EXTEN '39631', LAC 23, AUTH 1
20170425165529381 <000d> db.c:1156 Sync Equipment IMEI=356853052645650, classmark1=30, classmark2=30 58 a6 
20170425165530230 <0002> gsm_04_08_utils.c:662 -> CM SERVICE ACK
20170425165530780 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 ESTABLISH INDICATION
20170425165531489 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425165531489 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425165531489 <0022> gsm_04_11.c:805 receiving data (trans_id=a)
20170425165531489 <0022> gsm_04_11.c:820  -> (new transaction)
20170425165531489 <0001> transaction.c:71 subscr=0x9e1c60, net=0x85fd90
20170425165531489 <0022> gsm0411_smc.c:87 SMC(0) instance created for network
20170425165531489 <0022> gsm0411_smr.c:85 SMR(0) instance created for network.
20170425165531489 <0022> gsm0411_smc.c:567 SMC(0) message MMSMS-EST-IND (CP DATA) received in state IDLE
20170425165531489 <0022> gsm0411_smc.c:284 SMC(0) received CP-DATA
20170425165531489 <0022> gsm0411_smc.c:133 SMC(0) new CP state IDLE -> MM_ESTABLISHED
20170425165531489 <0022> gsm_04_11.c:143 sending CP message (trans=a)
20170425165531489 <0022> gsm_04_11.c:127 GSM4.11 TX a9 04 
20170425165531489 <0022> gsm_04_11.c:769 MNSMS-DATA/EST-IND
20170425165531489 <0022> gsm0411_smr.c:483 SMR(0) message MNSMS-EST-IND received in state IDLE
20170425165531489 <0022> gsm0411_smr.c:257 SMR(0) RX SMS RP-DATA
20170425165531489 <0022> gsm0411_smr.c:139 SMR(0) new RP state IDLE -> WAIT_TO_TX_RP_ACK
20170425165531489 <0022> gsm_04_11.c:686 RX SMS RP-DATA (MO)
20170425165531489 <0022> gsm_04_11.c:586 RX_RP-DATA: src_len=0, dst_len=2 ud_len=32
20170425165531489 <0022> gsm_04_11.c:554 DST(2,91 f7 )
20170425165531489 <0022> gsm_04_11.c:478 RX SMS: Sender: 901700000009029, MTI: 0x01, VPF: 0x02, MR: 0x02 PID: 0x00, DCS: 0x00, DA: 45678, UserDataLength: 0x17, UserData: "test sms from /sierra_2" 
20170425165531489 <0022> sms_queue.c:333 Triggering SMS queue
20170425165531492 <000d> db.c:915 Found Subscriber: ID 3, IMSI 901700000009032, NAME '', TMSI aef5e563, EXTEN '45678', LAC 23, AUTH 1
20170425165532807 <0022> sms_queue.c:333 Triggering SMS queue
20170425165532807 <0022> gsm_04_11.c:513 TX: SMS RP ACK
20170425165532807 <0022> gsm0411_smr.c:416 SMR(0) message SM-RL-REPORT_REQ received in state WAIT_TO_TX_RP_ACK
20170425165532807 <0022> gsm0411_smr.c:226 SMR(0) TX SMS REPORT
20170425165532807 <0022> gsm0411_smr.c:139 SMR(0) new RP state WAIT_TO_TX_RP_ACK -> IDLE
20170425165532807 <0022> gsm0411_smc.c:467 SMC(0) message MNSMS-DATA-REQ received in state MM_ESTABLISHED
20170425165532807 <0022> gsm0411_smc.c:180 SMC(0) send CP data
20170425165532807 <0022> gsm0411_smc.c:133 SMC(0) new CP state MM_ESTABLISHED -> WAIT_CP_ACK
20170425165532807 <0022> gsm_04_11.c:143 sending CP message (trans=a)
20170425165532807 <0022> gsm_04_11.c:127 GSM4.11 TX a9 01 02 03 03 
20170425165532807 <0022> gsm0411_smr.c:185 SMR(0) TX: MNSMS-REL-REQ
20170425165532807 <0022> gsm0411_smc.c:467 SMC(0) message MNSMS-REL-REQ received in state WAIT_CP_ACK
20170425165532807 <0022> gsm0411_smc.c:332 SMC(0) cannot release yet current state: WAIT_CP_ACK
20170425165532807 <0022> sms_queue.c:220 Attempting to send 20 SMS
20170425165532818 <000d> db.c:915 Found Subscriber: ID 3, IMSI 901700000009032, NAME '', TMSI aef5e563, EXTEN '45678', LAC 23, AUTH 1
20170425165532820 <0022> sms_queue.c:235 Sending SMS round 1
20170425165532820 <0022> gsm_04_11.c:1008 Sending SMS: no connection open, start paging 901700000009032
20170425165532821 <0002> gsm_subscriber.c:190 Subscriber 901700000009032 not paged yet.
20170425165532821 <0007> paging.c:295 Start paging of subscriber IMSI:901700000009032 on bts 0.
20170425165532833 <0022> sms_queue.c:235 Sending SMS round 2
20170425165532833 <0022> sms_queue.c:251 Sending SMS done (loop) (1 attempted)
20170425165532833 <0022> sms_queue.c:286 SMSqueue added 1 messages in 2 rounds
20170425165533321 <0007> paging.c:85 Going to send paging commands: imsi: 901700000009032 tmsi: 0xaef5e563 for ch. type 1 (attempt 0)
20170425165533372 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425165533372 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425165533372 <0022> gsm_04_11.c:805 receiving data (trans_id=a)
20170425165533372 <0022> gsm0411_smc.c:567 SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
20170425165533373 <0022> gsm0411_smc.c:256 SMC(0) received CP-ACK
20170425165533373 <0022> gsm0411_smc.c:133 SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
20170425165533373 <0022> gsm0411_smc.c:268 SMC(0) we have pending release.
20170425165533373 <0022> gsm0411_smc.c:133 SMC(0) new CP state MM_ESTABLISHED -> IDLE
20170425165533373 <0022> gsm_04_11.c:166 Got MMSMS_REL_REQ, destroying transaction.
20170425165533373 <0022> gsm0411_smr.c:92 SMR(0) clearing SMR instance
20170425165533373 <0022> gsm0411_smc.c:94 SMC(0) clearing instance
20170425165533394 <0000> chan_alloc.c:486 (bts=0,trx=0,ts=0,ss=1) starting release sequence
20170425165533395 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVE -> RELEASE REQUESTED
20170425165533395 <0000> abis_rsl.c:1192 (bts=0,trx=0,ts=0,ss=1) RSL RLL RELEASE REQ (link_id=0x03, reason=1)
20170425165533395 <0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 1 Type: 1
20170425165533395 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=1) DEACTivate SACCH CMD
20170425165533405 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 RELEASE CONFIRMATION
20170425165533406 <0004> abis_rsl.c:2017 (bts=0,trx=0,ts=0,ss=1) waiting for SAPI=0 to be released.
20170425165533606 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 RELEASE INDICATION
20170425165533606 <0004> abis_rsl.c:1708 (bts=0,trx=0,ts=0,ss=1) T3111 expired: releasing RF Channel
20170425165533606 <0004> abis_rsl.c:859 (bts=0,trx=0,ts=0,ss=1) RF Channel Release
20170425165533627 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=1) RF CHANNEL RELEASE ACK
20170425165533628 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state RELEASE REQUESTED -> NONE
20170425165533822 <0007> paging.c:85 Going to send paging commands: imsi: 901700000009032 tmsi: 0xaef5e563 for ch. type 1 (attempt 1)
20170425165534014 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=1 as SDCCH
20170425165534014 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=1) Activating ARFCN(868) SS(1) lctype SDCCH r=OTHER ra=0x1b ta=0
20170425165534014 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425165534014 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state NONE -> ACTIVATION REQUESTED
20170425165534057 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=1) CHANNEL ACTIVATE ACK
20170425165534057 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVATION REQUESTED -> ACTIVE
20170425165534323 <0007> paging.c:85 Going to send paging commands: imsi: 901700000009032 tmsi: 0xaef5e563 for ch. type 1 (attempt 2)
20170425165534824 <0007> paging.c:85 Going to send paging commands: imsi: 901700000009032 tmsi: 0xaef5e563 for ch. type 1 (attempt 3)
20170425165535172 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=2 as SDCCH
20170425165535172 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=2) Activating ARFCN(868) SS(2) lctype SDCCH r=OTHER ra=0x17 ta=0
20170425165535172 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425165535172 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=2) state NONE -> ACTIVATION REQUESTED
20170425165535212 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=2) CHANNEL ACTIVATE ACK
20170425165535212 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=2) state ACTIVATION REQUESTED -> ACTIVE
20170425165535324 <0007> paging.c:85 Going to send paging commands: imsi: 901700000009032 tmsi: 0xaef5e563 for ch. type 1 (attempt 4)
20170425165535515 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=2) SAPI=0 ESTABLISH INDICATION
20170425165535515 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=6
20170425165535515 <0003> gsm_04_08.c:1462 PAGING RESPONSE: MI(TMSI)=2935350627
20170425165535516 <0003> gsm_04_08.c:1495 <- Channel was requested by 901700000009032
20170425165535516 <000d> db.c:1156 Sync Equipment IMEI=868323024275960, classmark1=30, classmark2=30 58 a6 
20170425165535531 <0007> paging.c:383 Stop paging 901700000009032 on bts 0, calling cbfn.
20170425165535531 <0022> gsm_04_11.c:965 paging_cb_send_sms(hooknum=1, event=0, msg=(nil),conn=0x9e4160, sms=0x9e42c0/id: 3)
20170425165535531 <0022> gsm_04_11.c:893 gsm411_send_sms()
20170425165535531 <0001> transaction.c:71 subscr=0x9d0020, net=0x85fd90
20170425165535531 <0022> gsm0411_smc.c:87 SMC(3) instance created for network
20170425165535531 <0022> gsm0411_smr.c:85 SMR(3) instance created for network.
20170425165535531 <0022> gsm_04_11.c:946 TX: SMS DELIVER
20170425165535549 <0022> gsm0411_smr.c:416 SMR(3) message SM-RL-DATA_REQ received in state IDLE
20170425165535549 <0022> gsm0411_smr.c:215 SMR(3) TX SMS RP-DATA
20170425165535549 <0022> gsm0411_smr.c:139 SMR(3) new RP state IDLE -> WAIT_FOR_RP_ACK
20170425165535549 <0022> gsm0411_smc.c:467 SMC(3) message MNSMS-EST-REQ received in state IDLE
20170425165535549 <0022> gsm0411_smc.c:133 SMC(3) new CP state IDLE -> MM_CONN_PENDING
20170425165535550 <0022> gsm0411_smc.c:567 SMC(3) message MMSMS-EST-CNF received in state MM_CONN_PENDING
20170425165535550 <0022> gsm0411_smc.c:180 SMC(3) send CP data
20170425165535550 <0022> gsm0411_smc.c:133 SMC(3) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
20170425165535550 <0022> gsm_04_11.c:143 sending CP message (trans=0)
20170425165535550 <0022> gsm_04_11.c:127 GSM4.11 TX 09 01 31 01 00 07 91 44 77 58 10 06 50 00 25 00 05 80 93 36 f1 00 00 71 40 52 41 55 53 00 17 f4 f2 9c 0e 9a b7 e7 20 b3 fc dd 06 bd e6 e9 b2 5c 1e 8e c8 00 
20170425165535550 <0000> abis_rsl.c:1150 (bts=0,trx=0,ts=0,ss=2) RSL RLL ESTABLISH REQ (link_id=0x03)
20170425165535988 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=2) SAPI=3 ESTABLISH CONFIRM
20170425165536933 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=2) SAPI=3 DATA INDICATION
20170425165536933 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425165536933 <0022> gsm_04_11.c:805 receiving data (trans_id=0)
20170425165536933 <0022> gsm0411_smc.c:567 SMC(3) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
20170425165536933 <0022> gsm0411_smc.c:256 SMC(3) received CP-ACK
20170425165536933 <0022> gsm0411_smc.c:133 SMC(3) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
20170425165537165 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=2) SAPI=3 DATA INDICATION
20170425165537165 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425165537165 <0022> gsm_04_11.c:805 receiving data (trans_id=0)
20170425165537165 <0022> gsm0411_smc.c:567 SMC(3) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
20170425165537165 <0022> gsm0411_smc.c:284 SMC(3) received CP-DATA
20170425165537165 <0022> gsm_04_11.c:143 sending CP message (trans=0)
20170425165537165 <0022> gsm_04_11.c:127 GSM4.11 TX 09 04 
20170425165537165 <0022> gsm_04_11.c:769 MNSMS-DATA/EST-IND
20170425165537165 <0022> gsm0411_smr.c:483 SMR(3) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
20170425165537165 <0022> gsm0411_smr.c:309 SMR(3) RX SMS RP-ACK
20170425165537165 <0022> gsm0411_smr.c:139 SMR(3) new RP state WAIT_FOR_RP_ACK -> IDLE
20170425165537165 <0022> gsm_04_11.c:712 RX SMS RP-ACK (MO)
20170425165537187 <0022> sms_queue.c:220 Attempting to send 20 SMS
20170425165537201 <0022> sms_queue.c:230 Sending SMS done (0 attempted)
20170425165537201 <0022> sms_queue.c:286 SMSqueue added 0 messages in 0 rounds
20170425165537201 <0022> gsm0411_smr.c:185 SMR(3) TX: MNSMS-REL-REQ
20170425165537201 <0022> gsm0411_smc.c:467 SMC(3) message MNSMS-REL-REQ received in state MM_ESTABLISHED
20170425165537201 <0022> gsm0411_smc.c:133 SMC(3) new CP state MM_ESTABLISHED -> IDLE
20170425165537201 <0022> gsm_04_11.c:166 Got MMSMS_REL_REQ, destroying transaction.
20170425165537201 <0022> gsm0411_smr.c:92 SMR(3) clearing SMR instance
20170425165537201 <0022> gsm0411_smc.c:94 SMC(3) clearing instance
20170425165537222 <0000> chan_alloc.c:486 (bts=0,trx=0,ts=0,ss=2) starting release sequence
20170425165537222 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=2) state ACTIVE -> RELEASE REQUESTED
20170425165537222 <0000> abis_rsl.c:1192 (bts=0,trx=0,ts=0,ss=2) RSL RLL RELEASE REQ (link_id=0x03, reason=1)
20170425165537222 <0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 2 Type: 1
20170425165537222 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=2) DEACTivate SACCH CMD
20170425165537222 <0004> abis_rsl.c:1424 (bts=0,trx=0,ts=0,ss=2): MEAS RES for inactive channel
20170425165537259 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=2) SAPI=3 RELEASE CONFIRMATION
20170425165537259 <0004> abis_rsl.c:2017 (bts=0,trx=0,ts=0,ss=2) waiting for SAPI=0 to be released.
20170425165537400 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=2) SAPI=0 RELEASE INDICATION
20170425165537400 <0004> abis_rsl.c:1708 (bts=0,trx=0,ts=0,ss=2) T3111 expired: releasing RF Channel
20170425165537400 <0004> abis_rsl.c:859 (bts=0,trx=0,ts=0,ss=2) RF Channel Release
20170425165537423 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=2) RF CHANNEL RELEASE ACK
20170425165537423 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=2) state RELEASE REQUESTED -> NONE
20170425165544058 <0004> abis_rsl.c:1698 (bts=0,trx=0,ts=0,ss=1) T3101 expired: no response to IMMEDIATE ASSIGN
20170425165544058 <0004> abis_rsl.c:857 (bts=0,trx=0,ts=0,ss=1) RF Channel Release due to error: 1
20170425165544058 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=1) DEACTivate SACCH CMD
20170425165544058 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVE -> RELEASE DUE ERROR
20170425165544119 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=1) RF CHANNEL RELEASE ACK
20170425165546120 <0004> abis_rsl.c:816 (bts=0,trx=0,ts=0,ss=1) is back in operation.
20170425165546120 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state RELEASE DUE ERROR -> NONE

#4 Updated by neels 5 months ago

remaining nitb log


20170425165757281 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=1 as SDCCH
20170425165757281 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=1) Activating ARFCN(868) SS(1) lctype SDCCH r=OTHER ra=0x18 ta=0
20170425165757281 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425165757281 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state NONE -> ACTIVATION REQUESTED
20170425165757324 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=1) CHANNEL ACTIVATE ACK
20170425165757324 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVATION REQUESTED -> ACTIVE
20170425165757643 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 ESTABLISH INDICATION
20170425165757643 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425165757643 <0002> gsm_04_08.c:1016 <- CM SERVICE REQUEST serv_type=0x04 MI(TMSI)=1577075595
20170425165757646 <000d> db.c:915 Found Subscriber: ID 6, IMSI 901700000009029, NAME '', TMSI 5e00438b, EXTEN '39631', LAC 23, AUTH 1
20170425165757648 <000d> db.c:1156 Sync Equipment IMEI=356853052645650, classmark1=30, classmark2=30 58 a6 
20170425165757666 <0002> gsm_04_08_utils.c:662 -> CM SERVICE ACK
20170425165758348 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 ESTABLISH INDICATION
20170425165759057 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425165759058 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425165759058 <0022> gsm_04_11.c:805 receiving data (trans_id=b)
20170425165759058 <0022> gsm_04_11.c:820  -> (new transaction)
20170425165759058 <0001> transaction.c:71 subscr=0x9e3870, net=0x85fd90
20170425165759058 <0022> gsm0411_smc.c:87 SMC(0) instance created for network
20170425165759058 <0022> gsm0411_smr.c:85 SMR(0) instance created for network.
20170425165759058 <0022> gsm0411_smc.c:567 SMC(0) message MMSMS-EST-IND (CP DATA) received in state IDLE
20170425165759058 <0022> gsm0411_smc.c:284 SMC(0) received CP-DATA
20170425165759058 <0022> gsm0411_smc.c:133 SMC(0) new CP state IDLE -> MM_ESTABLISHED
20170425165759058 <0022> gsm_04_11.c:143 sending CP message (trans=b)
20170425165759058 <0022> gsm_04_11.c:127 GSM4.11 TX b9 04 
20170425165759058 <0022> gsm_04_11.c:769 MNSMS-DATA/EST-IND
20170425165759058 <0022> gsm0411_smr.c:483 SMR(0) message MNSMS-EST-IND received in state IDLE
20170425165759058 <0022> gsm0411_smr.c:257 SMR(0) RX SMS RP-DATA
20170425165759058 <0022> gsm0411_smr.c:139 SMR(0) new RP state IDLE -> WAIT_TO_TX_RP_ACK
20170425165759058 <0022> gsm_04_11.c:686 RX SMS RP-DATA (MO)
20170425165759058 <0022> gsm_04_11.c:586 RX_RP-DATA: src_len=0, dst_len=2 ud_len=32
20170425165759058 <0022> gsm_04_11.c:554 DST(2,91 f7 )
20170425165759058 <0022> gsm_04_11.c:478 RX SMS: Sender: 901700000009029, MTI: 0x01, VPF: 0x02, MR: 0x03 PID: 0x00, DCS: 0x00, DA: 45678, UserDataLength: 0x17, UserData: "test sms from /sierra_2" 
20170425165759058 <0022> sms_queue.c:333 Triggering SMS queue
20170425165759061 <000d> db.c:915 Found Subscriber: ID 3, IMSI 901700000009032, NAME '', TMSI aef5e563, EXTEN '45678', LAC 23, AUTH 1
20170425165759078 <0022> sms_queue.c:333 Triggering SMS queue
20170425165759079 <0022> gsm_04_11.c:513 TX: SMS RP ACK
20170425165759079 <0022> gsm0411_smr.c:416 SMR(0) message SM-RL-REPORT_REQ received in state WAIT_TO_TX_RP_ACK
20170425165759079 <0022> gsm0411_smr.c:226 SMR(0) TX SMS REPORT
20170425165759079 <0022> gsm0411_smr.c:139 SMR(0) new RP state WAIT_TO_TX_RP_ACK -> IDLE
20170425165759079 <0022> gsm0411_smc.c:467 SMC(0) message MNSMS-DATA-REQ received in state MM_ESTABLISHED
20170425165759079 <0022> gsm0411_smc.c:180 SMC(0) send CP data
20170425165759079 <0022> gsm0411_smc.c:133 SMC(0) new CP state MM_ESTABLISHED -> WAIT_CP_ACK
20170425165759079 <0022> gsm_04_11.c:143 sending CP message (trans=b)
20170425165759079 <0022> gsm_04_11.c:127 GSM4.11 TX b9 01 02 03 04 
20170425165759079 <0022> gsm0411_smr.c:185 SMR(0) TX: MNSMS-REL-REQ
20170425165759079 <0022> gsm0411_smc.c:467 SMC(0) message MNSMS-REL-REQ received in state WAIT_CP_ACK
20170425165759079 <0022> gsm0411_smc.c:332 SMC(0) cannot release yet current state: WAIT_CP_ACK
20170425165759766 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425165759766 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425165759766 <0022> gsm_04_11.c:805 receiving data (trans_id=b)
20170425165759766 <0022> gsm0411_smc.c:567 SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
20170425165759766 <0022> gsm0411_smc.c:256 SMC(0) received CP-ACK
20170425165759766 <0022> gsm0411_smc.c:133 SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
20170425165759766 <0022> gsm0411_smc.c:268 SMC(0) we have pending release.
20170425165759766 <0022> gsm0411_smc.c:133 SMC(0) new CP state MM_ESTABLISHED -> IDLE
20170425165759767 <0022> gsm_04_11.c:166 Got MMSMS_REL_REQ, destroying transaction.
20170425165759767 <0022> gsm0411_smr.c:92 SMR(0) clearing SMR instance
20170425165759767 <0022> gsm0411_smc.c:94 SMC(0) clearing instance
20170425165759789 <0000> chan_alloc.c:486 (bts=0,trx=0,ts=0,ss=1) starting release sequence
20170425165759789 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVE -> RELEASE REQUESTED
20170425165759790 <0000> abis_rsl.c:1192 (bts=0,trx=0,ts=0,ss=1) RSL RLL RELEASE REQ (link_id=0x03, reason=1)
20170425165759790 <0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 1 Type: 1
20170425165759790 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=1) DEACTivate SACCH CMD
20170425165759812 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 RELEASE CONFIRMATION
20170425165759812 <0004> abis_rsl.c:2017 (bts=0,trx=0,ts=0,ss=1) waiting for SAPI=0 to be released.
20170425165759998 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 RELEASE INDICATION
20170425165759998 <0004> abis_rsl.c:1708 (bts=0,trx=0,ts=0,ss=1) T3111 expired: releasing RF Channel
20170425165759998 <0004> abis_rsl.c:859 (bts=0,trx=0,ts=0,ss=1) RF Channel Release
20170425165800021 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=1) RF CHANNEL RELEASE ACK
20170425165800021 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state RELEASE REQUESTED -> NONE
20170425165800058 <0022> sms_queue.c:220 Attempting to send 20 SMS
20170425165800069 <000d> db.c:915 Found Subscriber: ID 3, IMSI 901700000009032, NAME '', TMSI aef5e563, EXTEN '45678', LAC 23, AUTH 1
20170425165800071 <0022> sms_queue.c:235 Sending SMS round 1
20170425165800071 <0022> gsm_04_11.c:1008 Sending SMS: no connection open, start paging 901700000009032
20170425165800071 <0002> gsm_subscriber.c:190 Subscriber 901700000009032 not paged yet.
20170425165800071 <0007> paging.c:295 Start paging of subscriber IMSI:901700000009032 on bts 0.
20170425165800083 <0022> sms_queue.c:235 Sending SMS round 2
20170425165800083 <0022> sms_queue.c:251 Sending SMS done (loop) (1 attempted)
20170425165800083 <0022> sms_queue.c:286 SMSqueue added 1 messages in 2 rounds
20170425165800572 <0007> paging.c:85 Going to send paging commands: imsi: 901700000009032 tmsi: 0xaef5e563 for ch. type 1 (attempt 0)
20170425165801073 <0007> paging.c:85 Going to send paging commands: imsi: 901700000009032 tmsi: 0xaef5e563 for ch. type 1 (attempt 1)
20170425165801088 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=1 as SDCCH
20170425165801089 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=1) Activating ARFCN(868) SS(1) lctype SDCCH r=OTHER ra=0x13 ta=0
20170425165801089 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425165801089 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state NONE -> ACTIVATION REQUESTED
20170425165801132 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=1) CHANNEL ACTIVATE ACK
20170425165801132 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVATION REQUESTED -> ACTIVE
20170425165801407 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 ESTABLISH INDICATION
20170425165801407 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=6
20170425165801407 <0003> gsm_04_08.c:1462 PAGING RESPONSE: MI(TMSI)=2935350627
20170425165801407 <0003> gsm_04_08.c:1495 <- Channel was requested by 901700000009032
20170425165801407 <000d> db.c:1156 Sync Equipment IMEI=868323024275960, classmark1=30, classmark2=30 58 a6 
20170425165801423 <0007> paging.c:383 Stop paging 901700000009032 on bts 0, calling cbfn.
20170425165801423 <0022> gsm_04_11.c:965 paging_cb_send_sms(hooknum=1, event=0, msg=(nil),conn=0x9d0a70, sms=0x9e1640/id: 4)
20170425165801423 <0022> gsm_04_11.c:893 gsm411_send_sms()
20170425165801423 <0001> transaction.c:71 subscr=0x9d0550, net=0x85fd90
20170425165801423 <0022> gsm0411_smc.c:87 SMC(4) instance created for network
20170425165801423 <0022> gsm0411_smr.c:85 SMR(4) instance created for network.
20170425165801424 <0022> gsm_04_11.c:946 TX: SMS DELIVER
20170425165801437 <0022> gsm0411_smr.c:416 SMR(4) message SM-RL-DATA_REQ received in state IDLE
20170425165801437 <0022> gsm0411_smr.c:215 SMR(4) TX SMS RP-DATA
20170425165801437 <0022> gsm0411_smr.c:139 SMR(4) new RP state IDLE -> WAIT_FOR_RP_ACK
20170425165801438 <0022> gsm0411_smc.c:467 SMC(4) message MNSMS-EST-REQ received in state IDLE
20170425165801438 <0022> gsm0411_smc.c:133 SMC(4) new CP state IDLE -> MM_CONN_PENDING
20170425165801438 <0022> gsm0411_smc.c:567 SMC(4) message MMSMS-EST-CNF received in state MM_CONN_PENDING
20170425165801438 <0022> gsm0411_smc.c:180 SMC(4) send CP data
20170425165801438 <0022> gsm0411_smc.c:133 SMC(4) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
20170425165801438 <0022> gsm_04_11.c:143 sending CP message (trans=0)
20170425165801438 <0022> gsm_04_11.c:127 GSM4.11 TX 09 01 31 01 00 07 91 44 77 58 10 06 50 00 25 00 05 80 93 36 f1 00 00 71 40 52 41 85 10 00 17 f4 f2 9c 0e 9a b7 e7 20 b3 fc dd 06 bd e6 e9 b2 5c 1e 8e c8 00 
20170425165801438 <0000> abis_rsl.c:1150 (bts=0,trx=0,ts=0,ss=1) RSL RLL ESTABLISH REQ (link_id=0x03)
20170425165801880 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 ESTABLISH CONFIRM
20170425165802825 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425165802826 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425165802826 <0022> gsm_04_11.c:805 receiving data (trans_id=0)
20170425165802826 <0022> gsm0411_smc.c:567 SMC(4) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
20170425165802826 <0022> gsm0411_smc.c:256 SMC(4) received CP-ACK
20170425165802826 <0022> gsm0411_smc.c:133 SMC(4) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
20170425165803057 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425165803057 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425165803057 <0022> gsm_04_11.c:805 receiving data (trans_id=0)
20170425165803057 <0022> gsm0411_smc.c:567 SMC(4) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
20170425165803057 <0022> gsm0411_smc.c:284 SMC(4) received CP-DATA
20170425165803057 <0022> gsm_04_11.c:143 sending CP message (trans=0)
20170425165803058 <0022> gsm_04_11.c:127 GSM4.11 TX 09 04 
20170425165803058 <0022> gsm_04_11.c:769 MNSMS-DATA/EST-IND
20170425165803058 <0022> gsm0411_smr.c:483 SMR(4) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
20170425165803058 <0022> gsm0411_smr.c:309 SMR(4) RX SMS RP-ACK
20170425165803058 <0022> gsm0411_smr.c:139 SMR(4) new RP state WAIT_FOR_RP_ACK -> IDLE
20170425165803058 <0022> gsm_04_11.c:712 RX SMS RP-ACK (MO)
20170425165803082 <0022> sms_queue.c:220 Attempting to send 20 SMS
20170425165803093 <0022> sms_queue.c:230 Sending SMS done (0 attempted)
20170425165803093 <0022> sms_queue.c:286 SMSqueue added 0 messages in 0 rounds
20170425165803093 <0022> gsm0411_smr.c:185 SMR(4) TX: MNSMS-REL-REQ
20170425165803093 <0022> gsm0411_smc.c:467 SMC(4) message MNSMS-REL-REQ received in state MM_ESTABLISHED
20170425165803093 <0022> gsm0411_smc.c:133 SMC(4) new CP state MM_ESTABLISHED -> IDLE
20170425165803093 <0022> gsm_04_11.c:166 Got MMSMS_REL_REQ, destroying transaction.
20170425165803093 <0022> gsm0411_smr.c:92 SMR(4) clearing SMR instance
20170425165803093 <0022> gsm0411_smc.c:94 SMC(4) clearing instance
20170425165803122 <0000> chan_alloc.c:486 (bts=0,trx=0,ts=0,ss=1) starting release sequence
20170425165803122 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVE -> RELEASE REQUESTED
20170425165803122 <0000> abis_rsl.c:1192 (bts=0,trx=0,ts=0,ss=1) RSL RLL RELEASE REQ (link_id=0x03, reason=1)
20170425165803122 <0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 1 Type: 1
20170425165803122 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=1) DEACTivate SACCH CMD
20170425165803159 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 RELEASE CONFIRMATION
20170425165803160 <0004> abis_rsl.c:2017 (bts=0,trx=0,ts=0,ss=1) waiting for SAPI=0 to be released.
20170425165803292 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 RELEASE INDICATION
20170425165803292 <0004> abis_rsl.c:1708 (bts=0,trx=0,ts=0,ss=1) T3111 expired: releasing RF Channel
20170425165803292 <0004> abis_rsl.c:859 (bts=0,trx=0,ts=0,ss=1) RF Channel Release
20170425165803314 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=1) RF CHANNEL RELEASE ACK
20170425165803315 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state RELEASE REQUESTED -> NONE
20170425165934257 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=1 as SDCCH
20170425165934257 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=1) Activating ARFCN(868) SS(1) lctype SDCCH r=OTHER ra=0x10 ta=0
20170425165934257 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425165934257 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state NONE -> ACTIVATION REQUESTED
20170425165934300 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=1) CHANNEL ACTIVATE ACK
20170425165934300 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVATION REQUESTED -> ACTIVE
20170425165934608 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 ESTABLISH INDICATION
20170425165934608 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425165934608 <0002> gsm_04_08.c:1016 <- CM SERVICE REQUEST serv_type=0x04 MI(TMSI)=1577075595
20170425165934611 <000d> db.c:915 Found Subscriber: ID 6, IMSI 901700000009029, NAME '', TMSI 5e00438b, EXTEN '39631', LAC 23, AUTH 1
20170425165934613 <000d> db.c:1156 Sync Equipment IMEI=356853052645650, classmark1=30, classmark2=30 58 a6 
20170425165934634 <0002> gsm_04_08_utils.c:662 -> CM SERVICE ACK
20170425165935315 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 ESTABLISH INDICATION
20170425165936022 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425165936022 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425165936022 <0022> gsm_04_11.c:805 receiving data (trans_id=c)
20170425165936023 <0022> gsm_04_11.c:820  -> (new transaction)
20170425165936023 <0001> transaction.c:71 subscr=0x9e3870, net=0x85fd90
20170425165936023 <0022> gsm0411_smc.c:87 SMC(0) instance created for network
20170425165936023 <0022> gsm0411_smr.c:85 SMR(0) instance created for network.
20170425165936023 <0022> gsm0411_smc.c:567 SMC(0) message MMSMS-EST-IND (CP DATA) received in state IDLE
20170425165936023 <0022> gsm0411_smc.c:284 SMC(0) received CP-DATA
20170425165936023 <0022> gsm0411_smc.c:133 SMC(0) new CP state IDLE -> MM_ESTABLISHED
20170425165936023 <0022> gsm_04_11.c:143 sending CP message (trans=c)
20170425165936023 <0022> gsm_04_11.c:127 GSM4.11 TX c9 04 
20170425165936023 <0022> gsm_04_11.c:769 MNSMS-DATA/EST-IND
20170425165936023 <0022> gsm0411_smr.c:483 SMR(0) message MNSMS-EST-IND received in state IDLE
20170425165936023 <0022> gsm0411_smr.c:257 SMR(0) RX SMS RP-DATA
20170425165936023 <0022> gsm0411_smr.c:139 SMR(0) new RP state IDLE -> WAIT_TO_TX_RP_ACK
20170425165936023 <0022> gsm_04_11.c:686 RX SMS RP-DATA (MO)
20170425165936023 <0022> gsm_04_11.c:586 RX_RP-DATA: src_len=0, dst_len=2 ud_len=32
20170425165936023 <0022> gsm_04_11.c:554 DST(2,91 f7 )
20170425165936023 <0022> gsm_04_11.c:478 RX SMS: Sender: 901700000009029, MTI: 0x01, VPF: 0x02, MR: 0x04 PID: 0x00, DCS: 0x00, DA: 39631, UserDataLength: 0x17, UserData: "test sms from /sierra_2" 
20170425165936023 <0022> sms_queue.c:333 Triggering SMS queue
20170425165936039 <0022> sms_queue.c:333 Triggering SMS queue
20170425165936039 <0022> gsm_04_11.c:513 TX: SMS RP ACK
20170425165936039 <0022> gsm0411_smr.c:416 SMR(0) message SM-RL-REPORT_REQ received in state WAIT_TO_TX_RP_ACK
20170425165936039 <0022> gsm0411_smr.c:226 SMR(0) TX SMS REPORT
20170425165936039 <0022> gsm0411_smr.c:139 SMR(0) new RP state WAIT_TO_TX_RP_ACK -> IDLE
20170425165936039 <0022> gsm0411_smc.c:467 SMC(0) message MNSMS-DATA-REQ received in state MM_ESTABLISHED
20170425165936039 <0022> gsm0411_smc.c:180 SMC(0) send CP data
20170425165936039 <0022> gsm0411_smc.c:133 SMC(0) new CP state MM_ESTABLISHED -> WAIT_CP_ACK
20170425165936039 <0022> gsm_04_11.c:143 sending CP message (trans=c)
20170425165936039 <0022> gsm_04_11.c:127 GSM4.11 TX c9 01 02 03 05 
20170425165936039 <0022> gsm0411_smr.c:185 SMR(0) TX: MNSMS-REL-REQ
20170425165936039 <0022> gsm0411_smc.c:467 SMC(0) message MNSMS-REL-REQ received in state WAIT_CP_ACK
20170425165936039 <0022> gsm0411_smc.c:332 SMC(0) cannot release yet current state: WAIT_CP_ACK
20170425165936731 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425165936731 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425165936731 <0022> gsm_04_11.c:805 receiving data (trans_id=c)
20170425165936731 <0022> gsm0411_smc.c:567 SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
20170425165936731 <0022> gsm0411_smc.c:256 SMC(0) received CP-ACK
20170425165936732 <0022> gsm0411_smc.c:133 SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
20170425165936732 <0022> gsm0411_smc.c:268 SMC(0) we have pending release.
20170425165936732 <0022> gsm0411_smc.c:133 SMC(0) new CP state MM_ESTABLISHED -> IDLE
20170425165936732 <0022> gsm_04_11.c:166 Got MMSMS_REL_REQ, destroying transaction.
20170425165936732 <0022> gsm0411_smr.c:92 SMR(0) clearing SMR instance
20170425165936732 <0022> gsm0411_smc.c:94 SMC(0) clearing instance
20170425165936755 <0000> chan_alloc.c:486 (bts=0,trx=0,ts=0,ss=1) starting release sequence
20170425165936755 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVE -> RELEASE REQUESTED
20170425165936755 <0000> abis_rsl.c:1192 (bts=0,trx=0,ts=0,ss=1) RSL RLL RELEASE REQ (link_id=0x03, reason=1)
20170425165936755 <0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 1 Type: 1
20170425165936755 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=1) DEACTivate SACCH CMD
20170425165936778 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 RELEASE CONFIRMATION
20170425165936778 <0004> abis_rsl.c:2017 (bts=0,trx=0,ts=0,ss=1) waiting for SAPI=0 to be released.
20170425165936964 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 RELEASE INDICATION
20170425165936964 <0004> abis_rsl.c:1708 (bts=0,trx=0,ts=0,ss=1) T3111 expired: releasing RF Channel
20170425165936964 <0004> abis_rsl.c:859 (bts=0,trx=0,ts=0,ss=1) RF Channel Release
20170425165936987 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=1) RF CHANNEL RELEASE ACK
20170425165936987 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state RELEASE REQUESTED -> NONE
20170425165937023 <0022> sms_queue.c:220 Attempting to send 20 SMS
20170425165937033 <000d> db.c:915 Found Subscriber: ID 6, IMSI 901700000009029, NAME '', TMSI 5e00438b, EXTEN '39631', LAC 23, AUTH 1
20170425165937036 <0022> sms_queue.c:235 Sending SMS round 1
20170425165937036 <0022> gsm_04_11.c:1008 Sending SMS: no connection open, start paging 901700000009029
20170425165937036 <0002> gsm_subscriber.c:190 Subscriber 901700000009029 not paged yet.
20170425165937036 <0007> paging.c:295 Start paging of subscriber IMSI:901700000009029 on bts 0.
20170425165937047 <0022> sms_queue.c:235 Sending SMS round 2
20170425165937048 <0022> sms_queue.c:251 Sending SMS done (loop) (1 attempted)
20170425165937048 <0022> sms_queue.c:286 SMSqueue added 1 messages in 2 rounds
20170425165937536 <0007> paging.c:85 Going to send paging commands: imsi: 901700000009029 tmsi: 0x5e00438b for ch. type 1 (attempt 0)
20170425165938037 <0007> paging.c:85 Going to send paging commands: imsi: 901700000009029 tmsi: 0x5e00438b for ch. type 1 (attempt 1)
20170425165938303 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=1 as SDCCH
20170425165938303 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=1) Activating ARFCN(868) SS(1) lctype SDCCH r=OTHER ra=0x13 ta=0
20170425165938303 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425165938303 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state NONE -> ACTIVATION REQUESTED
20170425165938345 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=1) CHANNEL ACTIVATE ACK
20170425165938345 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVATION REQUESTED -> ACTIVE
20170425165938538 <0007> paging.c:85 Going to send paging commands: imsi: 901700000009029 tmsi: 0x5e00438b for ch. type 1 (attempt 2)
20170425165938609 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 ESTABLISH INDICATION
20170425165938609 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=6
20170425165938609 <0003> gsm_04_08.c:1462 PAGING RESPONSE: MI(TMSI)=1577075595
20170425165938609 <0003> gsm_04_08.c:1495 <- Channel was requested by 901700000009029
20170425165938609 <000d> db.c:1156 Sync Equipment IMEI=356853052645650, classmark1=30, classmark2=30 58 a6 
20170425165938624 <0007> paging.c:383 Stop paging 901700000009029 on bts 0, calling cbfn.
20170425165938624 <0022> gsm_04_11.c:965 paging_cb_send_sms(hooknum=1, event=0, msg=(nil),conn=0x9cf8e0, sms=0x9e1640/id: 5)
20170425165938624 <0022> gsm_04_11.c:893 gsm411_send_sms()
20170425165938624 <0001> transaction.c:71 subscr=0x9d0550, net=0x85fd90
20170425165938625 <0022> gsm0411_smc.c:87 SMC(5) instance created for network
20170425165938625 <0022> gsm0411_smr.c:85 SMR(5) instance created for network.
20170425165938625 <0022> gsm_04_11.c:946 TX: SMS DELIVER
20170425165938641 <0022> gsm0411_smr.c:416 SMR(5) message SM-RL-DATA_REQ received in state IDLE
20170425165938641 <0022> gsm0411_smr.c:215 SMR(5) TX SMS RP-DATA
20170425165938641 <0022> gsm0411_smr.c:139 SMR(5) new RP state IDLE -> WAIT_FOR_RP_ACK
20170425165938641 <0022> gsm0411_smc.c:467 SMC(5) message MNSMS-EST-REQ received in state IDLE
20170425165938641 <0022> gsm0411_smc.c:133 SMC(5) new CP state IDLE -> MM_CONN_PENDING
20170425165938641 <0022> gsm0411_smc.c:567 SMC(5) message MMSMS-EST-CNF received in state MM_CONN_PENDING
20170425165938641 <0022> gsm0411_smc.c:180 SMC(5) send CP data
20170425165938641 <0022> gsm0411_smc.c:133 SMC(5) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
20170425165938641 <0022> gsm_04_11.c:143 sending CP message (trans=0)
20170425165938641 <0022> gsm_04_11.c:127 GSM4.11 TX 09 01 31 01 00 07 91 44 77 58 10 06 50 00 25 00 05 80 93 36 f1 00 00 71 40 52 41 95 83 00 17 f4 f2 9c 0e 9a b7 e7 20 b3 fc dd 06 bd e6 e9 b2 5c 1e 8e c8 00 
20170425165938641 <0000> abis_rsl.c:1150 (bts=0,trx=0,ts=0,ss=1) RSL RLL ESTABLISH REQ (link_id=0x03)
20170425165939083 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 ESTABLISH CONFIRM
20170425165940026 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425165940026 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425165940026 <0022> gsm_04_11.c:805 receiving data (trans_id=0)
20170425165940026 <0022> gsm0411_smc.c:567 SMC(5) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
20170425165940026 <0022> gsm0411_smc.c:256 SMC(5) received CP-ACK
20170425165940026 <0022> gsm0411_smc.c:133 SMC(5) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
20170425165940260 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425165940260 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425165940260 <0022> gsm_04_11.c:805 receiving data (trans_id=0)
20170425165940260 <0022> gsm0411_smc.c:567 SMC(5) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
20170425165940260 <0022> gsm0411_smc.c:284 SMC(5) received CP-DATA
20170425165940260 <0022> gsm_04_11.c:143 sending CP message (trans=0)
20170425165940260 <0022> gsm_04_11.c:127 GSM4.11 TX 09 04 
20170425165940260 <0022> gsm_04_11.c:769 MNSMS-DATA/EST-IND
20170425165940260 <0022> gsm0411_smr.c:483 SMR(5) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
20170425165940260 <0022> gsm0411_smr.c:309 SMR(5) RX SMS RP-ACK
20170425165940260 <0022> gsm0411_smr.c:139 SMR(5) new RP state WAIT_FOR_RP_ACK -> IDLE
20170425165940260 <0022> gsm_04_11.c:712 RX SMS RP-ACK (MO)
20170425165940286 <0022> sms_queue.c:220 Attempting to send 20 SMS
20170425165940299 <0022> sms_queue.c:230 Sending SMS done (0 attempted)
20170425165940299 <0022> sms_queue.c:286 SMSqueue added 0 messages in 0 rounds
20170425165940299 <0022> gsm0411_smr.c:185 SMR(5) TX: MNSMS-REL-REQ
20170425165940299 <0022> gsm0411_smc.c:467 SMC(5) message MNSMS-REL-REQ received in state MM_ESTABLISHED
20170425165940299 <0022> gsm0411_smc.c:133 SMC(5) new CP state MM_ESTABLISHED -> IDLE
20170425165940299 <0022> gsm_04_11.c:166 Got MMSMS_REL_REQ, destroying transaction.
20170425165940299 <0022> gsm0411_smr.c:92 SMR(5) clearing SMR instance
20170425165940299 <0022> gsm0411_smc.c:94 SMC(5) clearing instance
20170425165940320 <0000> chan_alloc.c:486 (bts=0,trx=0,ts=0,ss=1) starting release sequence
20170425165940320 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVE -> RELEASE REQUESTED
20170425165940321 <0000> abis_rsl.c:1192 (bts=0,trx=0,ts=0,ss=1) RSL RLL RELEASE REQ (link_id=0x03, reason=1)
20170425165940321 <0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 1 Type: 1
20170425165940321 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=1) DEACTivate SACCH CMD
20170425165940365 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 RELEASE CONFIRMATION
20170425165940366 <0004> abis_rsl.c:2017 (bts=0,trx=0,ts=0,ss=1) waiting for SAPI=0 to be released.
20170425165940374 <0004> abis_rsl.c:1424 (bts=0,trx=0,ts=0,ss=1): MEAS RES for inactive channel
20170425165940494 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 RELEASE INDICATION
20170425165940494 <0004> abis_rsl.c:1708 (bts=0,trx=0,ts=0,ss=1) T3111 expired: releasing RF Channel
20170425165940494 <0004> abis_rsl.c:859 (bts=0,trx=0,ts=0,ss=1) RF Channel Release
20170425165940516 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=1) RF CHANNEL RELEASE ACK
20170425165940516 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state RELEASE REQUESTED -> NONE
20170425170025301 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=1 as SDCCH
20170425170025301 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=1) Activating ARFCN(868) SS(1) lctype SDCCH r=OTHER ra=0x11 ta=0
20170425170025301 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425170025301 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state NONE -> ACTIVATION REQUESTED
20170425170025343 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=1) CHANNEL ACTIVATE ACK
20170425170025343 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVATION REQUESTED -> ACTIVE
20170425170025680 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 ESTABLISH INDICATION
20170425170025680 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425170025680 <0002> gsm_04_08.c:1016 <- CM SERVICE REQUEST serv_type=0x04 MI(TMSI)=1577075595
20170425170025683 <000d> db.c:915 Found Subscriber: ID 6, IMSI 901700000009029, NAME '', TMSI 5e00438b, EXTEN '39631', LAC 23, AUTH 1
20170425170025686 <000d> db.c:1156 Sync Equipment IMEI=356853052645650, classmark1=30, classmark2=30 58 a6 
20170425170025703 <0002> gsm_04_08_utils.c:662 -> CM SERVICE ACK
20170425170026387 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 ESTABLISH INDICATION
20170425170027094 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425170027094 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425170027095 <0022> gsm_04_11.c:805 receiving data (trans_id=d)
20170425170027095 <0022> gsm_04_11.c:820  -> (new transaction)
20170425170027095 <0001> transaction.c:71 subscr=0x9e3870, net=0x85fd90
20170425170027095 <0022> gsm0411_smc.c:87 SMC(0) instance created for network
20170425170027095 <0022> gsm0411_smr.c:85 SMR(0) instance created for network.
20170425170027095 <0022> gsm0411_smc.c:567 SMC(0) message MMSMS-EST-IND (CP DATA) received in state IDLE
20170425170027095 <0022> gsm0411_smc.c:284 SMC(0) received CP-DATA
20170425170027095 <0022> gsm0411_smc.c:133 SMC(0) new CP state IDLE -> MM_ESTABLISHED
20170425170027095 <0022> gsm_04_11.c:143 sending CP message (trans=d)
20170425170027095 <0022> gsm_04_11.c:127 GSM4.11 TX d9 04 
20170425170027095 <0022> gsm_04_11.c:769 MNSMS-DATA/EST-IND
20170425170027095 <0022> gsm0411_smr.c:483 SMR(0) message MNSMS-EST-IND received in state IDLE
20170425170027095 <0022> gsm0411_smr.c:257 SMR(0) RX SMS RP-DATA
20170425170027095 <0022> gsm0411_smr.c:139 SMR(0) new RP state IDLE -> WAIT_TO_TX_RP_ACK
20170425170027095 <0022> gsm_04_11.c:686 RX SMS RP-DATA (MO)
20170425170027095 <0022> gsm_04_11.c:586 RX_RP-DATA: src_len=0, dst_len=2 ud_len=32
20170425170027095 <0022> gsm_04_11.c:554 DST(2,91 f7 )
20170425170027095 <0022> gsm_04_11.c:478 RX SMS: Sender: 901700000009029, MTI: 0x01, VPF: 0x02, MR: 0x05 PID: 0x00, DCS: 0x00, DA: 22771, UserDataLength: 0x17, UserData: "test sms from /sierra_2" 
20170425170027095 <0022> sms_queue.c:333 Triggering SMS queue
20170425170027098 <000d> db.c:915 Found Subscriber: ID 5, IMSI 901700000009031, NAME '', TMSI ffffffff, EXTEN '22771', LAC 0, AUTH 1
20170425170027118 <0022> sms_queue.c:333 Triggering SMS queue
20170425170027118 <0022> gsm_04_11.c:513 TX: SMS RP ACK
20170425170027118 <0022> gsm0411_smr.c:416 SMR(0) message SM-RL-REPORT_REQ received in state WAIT_TO_TX_RP_ACK
20170425170027118 <0022> gsm0411_smr.c:226 SMR(0) TX SMS REPORT
20170425170027118 <0022> gsm0411_smr.c:139 SMR(0) new RP state WAIT_TO_TX_RP_ACK -> IDLE
20170425170027118 <0022> gsm0411_smc.c:467 SMC(0) message MNSMS-DATA-REQ received in state MM_ESTABLISHED
20170425170027118 <0022> gsm0411_smc.c:180 SMC(0) send CP data
20170425170027118 <0022> gsm0411_smc.c:133 SMC(0) new CP state MM_ESTABLISHED -> WAIT_CP_ACK
20170425170027118 <0022> gsm_04_11.c:143 sending CP message (trans=d)
20170425170027118 <0022> gsm_04_11.c:127 GSM4.11 TX d9 01 02 03 06 
20170425170027118 <0022> gsm0411_smr.c:185 SMR(0) TX: MNSMS-REL-REQ
20170425170027118 <0022> gsm0411_smc.c:467 SMC(0) message MNSMS-REL-REQ received in state WAIT_CP_ACK
20170425170027118 <0022> gsm0411_smc.c:332 SMC(0) cannot release yet current state: WAIT_CP_ACK
20170425170027803 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425170027803 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425170027803 <0022> gsm_04_11.c:805 receiving data (trans_id=d)
20170425170027803 <0022> gsm0411_smc.c:567 SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
20170425170027803 <0022> gsm0411_smc.c:256 SMC(0) received CP-ACK
20170425170027803 <0022> gsm0411_smc.c:133 SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
20170425170027803 <0022> gsm0411_smc.c:268 SMC(0) we have pending release.
20170425170027803 <0022> gsm0411_smc.c:133 SMC(0) new CP state MM_ESTABLISHED -> IDLE
20170425170027803 <0022> gsm_04_11.c:166 Got MMSMS_REL_REQ, destroying transaction.
20170425170027803 <0022> gsm0411_smr.c:92 SMR(0) clearing SMR instance
20170425170027803 <0022> gsm0411_smc.c:94 SMC(0) clearing instance
20170425170027827 <0000> chan_alloc.c:486 (bts=0,trx=0,ts=0,ss=1) starting release sequence
20170425170027827 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVE -> RELEASE REQUESTED
20170425170027827 <0000> abis_rsl.c:1192 (bts=0,trx=0,ts=0,ss=1) RSL RLL RELEASE REQ (link_id=0x03, reason=1)
20170425170027827 <0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 1 Type: 1
20170425170027827 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=1) DEACTivate SACCH CMD
20170425170027851 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 RELEASE CONFIRMATION
20170425170027851 <0004> abis_rsl.c:2017 (bts=0,trx=0,ts=0,ss=1) waiting for SAPI=0 to be released.
20170425170028035 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 RELEASE INDICATION
20170425170028035 <0004> abis_rsl.c:1708 (bts=0,trx=0,ts=0,ss=1) T3111 expired: releasing RF Channel
20170425170028035 <0004> abis_rsl.c:859 (bts=0,trx=0,ts=0,ss=1) RF Channel Release
20170425170028059 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=1) RF CHANNEL RELEASE ACK
20170425170028059 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state RELEASE REQUESTED -> NONE
20170425170028095 <0022> sms_queue.c:220 Attempting to send 20 SMS
20170425170028109 <0022> sms_queue.c:230 Sending SMS done (0 attempted)
20170425170028109 <0022> sms_queue.c:286 SMSqueue added 0 messages in 0 rounds

20170425170127913 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=1 as SDCCH
20170425170127914 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=1) Activating ARFCN(868) SS(1) lctype SDCCH r=OTHER ra=0x18 ta=0
20170425170127914 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425170127914 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state NONE -> ACTIVATION REQUESTED
20170425170127955 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=1) CHANNEL ACTIVATE ACK
20170425170127955 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVATION REQUESTED -> ACTIVE
20170425170128284 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 ESTABLISH INDICATION
20170425170128285 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=5
20170425170128285 <0002> gsm_04_08.c:1016 <- CM SERVICE REQUEST serv_type=0x04 MI(TMSI)=1577075595
20170425170128288 <000d> db.c:915 Found Subscriber: ID 6, IMSI 901700000009029, NAME '', TMSI 5e00438b, EXTEN '39631', LAC 23, AUTH 1
20170425170128290 <000d> db.c:1156 Sync Equipment IMEI=356853052645650, classmark1=30, classmark2=30 58 a6 
20170425170128310 <0002> gsm_04_08_utils.c:662 -> CM SERVICE ACK
20170425170128990 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 ESTABLISH INDICATION
20170425170129699 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425170129699 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425170129699 <0022> gsm_04_11.c:805 receiving data (trans_id=e)
20170425170129699 <0022> gsm_04_11.c:820  -> (new transaction)
20170425170129699 <0001> transaction.c:71 subscr=0x9e3870, net=0x85fd90
20170425170129699 <0022> gsm0411_smc.c:87 SMC(0) instance created for network
20170425170129699 <0022> gsm0411_smr.c:85 SMR(0) instance created for network.
20170425170129699 <0022> gsm0411_smc.c:567 SMC(0) message MMSMS-EST-IND (CP DATA) received in state IDLE
20170425170129699 <0022> gsm0411_smc.c:284 SMC(0) received CP-DATA
20170425170129699 <0022> gsm0411_smc.c:133 SMC(0) new CP state IDLE -> MM_ESTABLISHED
20170425170129699 <0022> gsm_04_11.c:143 sending CP message (trans=e)
20170425170129699 <0022> gsm_04_11.c:127 GSM4.11 TX e9 04 
20170425170129699 <0022> gsm_04_11.c:769 MNSMS-DATA/EST-IND
20170425170129699 <0022> gsm0411_smr.c:483 SMR(0) message MNSMS-EST-IND received in state IDLE
20170425170129699 <0022> gsm0411_smr.c:257 SMR(0) RX SMS RP-DATA
20170425170129699 <0022> gsm0411_smr.c:139 SMR(0) new RP state IDLE -> WAIT_TO_TX_RP_ACK
20170425170129699 <0022> gsm_04_11.c:686 RX SMS RP-DATA (MO)
20170425170129699 <0022> gsm_04_11.c:586 RX_RP-DATA: src_len=0, dst_len=2 ud_len=32
20170425170129699 <0022> gsm_04_11.c:554 DST(2,91 f7 )
20170425170129699 <0022> gsm_04_11.c:478 RX SMS: Sender: 901700000009029, MTI: 0x01, VPF: 0x02, MR: 0x06 PID: 0x00, DCS: 0x00, DA: 48292, UserDataLength: 0x17, UserData: "test sms from /sierra_2" 
20170425170129699 <0022> sms_queue.c:333 Triggering SMS queue
20170425170129702 <000d> db.c:915 Found Subscriber: ID 4, IMSI 901700000009030, NAME '', TMSI c46031b, EXTEN '48292', LAC 23, AUTH 1
20170425170129720 <0022> sms_queue.c:333 Triggering SMS queue
20170425170129720 <0022> gsm_04_11.c:513 TX: SMS RP ACK
20170425170129720 <0022> gsm0411_smr.c:416 SMR(0) message SM-RL-REPORT_REQ received in state WAIT_TO_TX_RP_ACK
20170425170129720 <0022> gsm0411_smr.c:226 SMR(0) TX SMS REPORT
20170425170129720 <0022> gsm0411_smr.c:139 SMR(0) new RP state WAIT_TO_TX_RP_ACK -> IDLE
20170425170129720 <0022> gsm0411_smc.c:467 SMC(0) message MNSMS-DATA-REQ received in state MM_ESTABLISHED
20170425170129720 <0022> gsm0411_smc.c:180 SMC(0) send CP data
20170425170129720 <0022> gsm0411_smc.c:133 SMC(0) new CP state MM_ESTABLISHED -> WAIT_CP_ACK
20170425170129721 <0022> gsm_04_11.c:143 sending CP message (trans=e)
20170425170129721 <0022> gsm_04_11.c:127 GSM4.11 TX e9 01 02 03 07 
20170425170129721 <0022> gsm0411_smr.c:185 SMR(0) TX: MNSMS-REL-REQ
20170425170129721 <0022> gsm0411_smc.c:467 SMC(0) message MNSMS-REL-REQ received in state WAIT_CP_ACK
20170425170129721 <0022> gsm0411_smc.c:332 SMC(0) cannot release yet current state: WAIT_CP_ACK
20170425170130409 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425170130409 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425170130409 <0022> gsm_04_11.c:805 receiving data (trans_id=e)
20170425170130409 <0022> gsm0411_smc.c:567 SMC(0) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
20170425170130409 <0022> gsm0411_smc.c:256 SMC(0) received CP-ACK
20170425170130409 <0022> gsm0411_smc.c:133 SMC(0) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
20170425170130409 <0022> gsm0411_smc.c:268 SMC(0) we have pending release.
20170425170130409 <0022> gsm0411_smc.c:133 SMC(0) new CP state MM_ESTABLISHED -> IDLE
20170425170130409 <0022> gsm_04_11.c:166 Got MMSMS_REL_REQ, destroying transaction.
20170425170130409 <0022> gsm0411_smr.c:92 SMR(0) clearing SMR instance
20170425170130409 <0022> gsm0411_smc.c:94 SMC(0) clearing instance
20170425170130432 <0000> chan_alloc.c:486 (bts=0,trx=0,ts=0,ss=1) starting release sequence
20170425170130432 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVE -> RELEASE REQUESTED
20170425170130432 <0000> abis_rsl.c:1192 (bts=0,trx=0,ts=0,ss=1) RSL RLL RELEASE REQ (link_id=0x03, reason=1)
20170425170130433 <0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 1 Type: 1
20170425170130433 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=1) DEACTivate SACCH CMD
20170425170130453 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 RELEASE CONFIRMATION
20170425170130453 <0004> abis_rsl.c:2017 (bts=0,trx=0,ts=0,ss=1) waiting for SAPI=0 to be released.
20170425170130639 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 RELEASE INDICATION
20170425170130639 <0004> abis_rsl.c:1708 (bts=0,trx=0,ts=0,ss=1) T3111 expired: releasing RF Channel
20170425170130639 <0004> abis_rsl.c:859 (bts=0,trx=0,ts=0,ss=1) RF Channel Release
20170425170130659 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=1) RF CHANNEL RELEASE ACK
20170425170130659 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state RELEASE REQUESTED -> NONE
20170425170130700 <0022> sms_queue.c:220 Attempting to send 20 SMS
20170425170130709 <000d> db.c:915 Found Subscriber: ID 4, IMSI 901700000009030, NAME '', TMSI c46031b, EXTEN '48292', LAC 23, AUTH 1
20170425170130711 <0022> sms_queue.c:235 Sending SMS round 1
20170425170130711 <0022> gsm_04_11.c:1008 Sending SMS: no connection open, start paging 901700000009030
20170425170130711 <0002> gsm_subscriber.c:190 Subscriber 901700000009030 not paged yet.
20170425170130711 <0007> paging.c:295 Start paging of subscriber IMSI:901700000009030 on bts 0.
20170425170130723 <0022> sms_queue.c:235 Sending SMS round 2
20170425170130723 <0022> sms_queue.c:251 Sending SMS done (loop) (1 attempted)
20170425170130723 <0022> sms_queue.c:286 SMSqueue added 1 messages in 2 rounds
20170425170131212 <0007> paging.c:85 Going to send paging commands: imsi: 901700000009030 tmsi: 0x0c46031b for ch. type 1 (attempt 0)
20170425170131500 <0000> chan_alloc.c:352 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Allocating lchan=1 as SDCCH
20170425170131500 <0004> abis_rsl.c:1857 (bts=0,trx=0,ts=0,ss=1) Activating ARFCN(868) SS(1) lctype SDCCH r=OTHER ra=0x1c ta=0
20170425170131501 <0004> abis_rsl.c:585 (bts=0,trx=0,ts=0,pchan=CCCH+SDCCH4) Tx RSL Channel Activate with act_type=INITIAL
20170425170131501 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state NONE -> ACTIVATION REQUESTED
20170425170131543 <0004> abis_rsl.c:1580 (bts=0,trx=0,ts=0,ss=1) CHANNEL ACTIVATE ACK
20170425170131543 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVATION REQUESTED -> ACTIVE
20170425170131713 <0007> paging.c:85 Going to send paging commands: imsi: 901700000009030 tmsi: 0x0c46031b for ch. type 1 (attempt 1)
20170425170131815 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 ESTABLISH INDICATION
20170425170131815 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=6
20170425170131815 <0003> gsm_04_08.c:1462 PAGING RESPONSE: MI(TMSI)=205914907
20170425170131815 <0003> gsm_04_08.c:1495 <- Channel was requested by 901700000009030
20170425170131815 <000d> db.c:1156 Sync Equipment IMEI=868323024272130, classmark1=30, classmark2=30 58 a6 
20170425170131833 <0007> paging.c:383 Stop paging 901700000009030 on bts 0, calling cbfn.
20170425170131833 <0022> gsm_04_11.c:965 paging_cb_send_sms(hooknum=1, event=0, msg=(nil),conn=0x9d0a70, sms=0x9e1640/id: 7)
20170425170131833 <0022> gsm_04_11.c:893 gsm411_send_sms()
20170425170131833 <0001> transaction.c:71 subscr=0x9d0550, net=0x85fd90
20170425170131833 <0022> gsm0411_smc.c:87 SMC(7) instance created for network
20170425170131833 <0022> gsm0411_smr.c:85 SMR(7) instance created for network.
20170425170131833 <0022> gsm_04_11.c:946 TX: SMS DELIVER
20170425170131852 <0022> gsm0411_smr.c:416 SMR(7) message SM-RL-DATA_REQ received in state IDLE
20170425170131852 <0022> gsm0411_smr.c:215 SMR(7) TX SMS RP-DATA
20170425170131852 <0022> gsm0411_smr.c:139 SMR(7) new RP state IDLE -> WAIT_FOR_RP_ACK
20170425170131852 <0022> gsm0411_smc.c:467 SMC(7) message MNSMS-EST-REQ received in state IDLE
20170425170131852 <0022> gsm0411_smc.c:133 SMC(7) new CP state IDLE -> MM_CONN_PENDING
20170425170131852 <0022> gsm0411_smc.c:567 SMC(7) message MMSMS-EST-CNF received in state MM_CONN_PENDING
20170425170131852 <0022> gsm0411_smc.c:180 SMC(7) send CP data
20170425170131852 <0022> gsm0411_smc.c:133 SMC(7) new CP state MM_CONN_PENDING -> WAIT_CP_ACK
20170425170131852 <0022> gsm_04_11.c:143 sending CP message (trans=0)
20170425170131852 <0022> gsm_04_11.c:127 GSM4.11 TX 09 01 31 01 00 07 91 44 77 58 10 06 50 00 25 00 05 80 93 36 f1 00 00 71 40 52 51 10 13 00 17 f4 f2 9c 0e 9a b7 e7 20 b3 fc dd 06 bd e6 e9 b2 5c 1e 8e c8 00 
20170425170131852 <0000> abis_rsl.c:1150 (bts=0,trx=0,ts=0,ss=1) RSL RLL ESTABLISH REQ (link_id=0x03)
20170425170132287 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 ESTABLISH CONFIRM
20170425170133233 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425170133233 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425170133233 <0022> gsm_04_11.c:805 receiving data (trans_id=0)
20170425170133233 <0022> gsm0411_smc.c:567 SMC(7) message MMSMS-DATA-IND (CP ACK) received in state WAIT_CP_ACK
20170425170133233 <0022> gsm0411_smc.c:256 SMC(7) received CP-ACK
20170425170133233 <0022> gsm0411_smc.c:133 SMC(7) new CP state WAIT_CP_ACK -> MM_ESTABLISHED
20170425170133464 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 DATA INDICATION
20170425170133464 <0000> gsm_04_08.c:4001 Dispatching 04.08 message, pdisc=9
20170425170133464 <0022> gsm_04_11.c:805 receiving data (trans_id=0)
20170425170133464 <0022> gsm0411_smc.c:567 SMC(7) message MMSMS-DATA-IND (CP DATA) received in state MM_ESTABLISHED
20170425170133464 <0022> gsm0411_smc.c:284 SMC(7) received CP-DATA
20170425170133464 <0022> gsm_04_11.c:143 sending CP message (trans=0)
20170425170133464 <0022> gsm_04_11.c:127 GSM4.11 TX 09 04 
20170425170133464 <0022> gsm_04_11.c:769 MNSMS-DATA/EST-IND
20170425170133464 <0022> gsm0411_smr.c:483 SMR(7) message MNSMS-DATA-IND received in state WAIT_FOR_RP_ACK
20170425170133464 <0022> gsm0411_smr.c:309 SMR(7) RX SMS RP-ACK
20170425170133464 <0022> gsm0411_smr.c:139 SMR(7) new RP state WAIT_FOR_RP_ACK -> IDLE
20170425170133464 <0022> gsm_04_11.c:712 RX SMS RP-ACK (MO)
20170425170133491 <0022> sms_queue.c:220 Attempting to send 20 SMS
20170425170133505 <0022> sms_queue.c:230 Sending SMS done (0 attempted)
20170425170133505 <0022> sms_queue.c:286 SMSqueue added 0 messages in 0 rounds
20170425170133505 <0022> gsm0411_smr.c:185 SMR(7) TX: MNSMS-REL-REQ
20170425170133505 <0022> gsm0411_smc.c:467 SMC(7) message MNSMS-REL-REQ received in state MM_ESTABLISHED
20170425170133505 <0022> gsm0411_smc.c:133 SMC(7) new CP state MM_ESTABLISHED -> IDLE
20170425170133505 <0022> gsm_04_11.c:166 Got MMSMS_REL_REQ, destroying transaction.
20170425170133505 <0022> gsm0411_smr.c:92 SMR(7) clearing SMR instance
20170425170133505 <0022> gsm0411_smc.c:94 SMC(7) clearing instance
20170425170133527 <0000> chan_alloc.c:486 (bts=0,trx=0,ts=0,ss=1) starting release sequence
20170425170133527 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state ACTIVE -> RELEASE REQUESTED
20170425170133527 <0000> abis_rsl.c:1192 (bts=0,trx=0,ts=0,ss=1) RSL RLL RELEASE REQ (link_id=0x03, reason=1)
20170425170133527 <0003> gsm_04_08_utils.c:251 Sending Channel Release: Chan: Number: 1 Type: 1
20170425170133527 <0004> abis_rsl.c:767 (bts=0,trx=0,ts=0,ss=1) DEACTivate SACCH CMD
20170425170133565 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=3 RELEASE CONFIRMATION
20170425170133565 <0004> abis_rsl.c:2017 (bts=0,trx=0,ts=0,ss=1) waiting for SAPI=0 to be released.
20170425170133699 <0000> abis_rsl.c:2047 (bts=0,trx=0,ts=0,ss=1) SAPI=0 RELEASE INDICATION
20170425170133699 <0004> abis_rsl.c:1708 (bts=0,trx=0,ts=0,ss=1) T3111 expired: releasing RF Channel
20170425170133700 <0004> abis_rsl.c:859 (bts=0,trx=0,ts=0,ss=1) RF Channel Release
20170425170133722 <0004> abis_rsl.c:930 (bts=0,trx=0,ts=0,ss=1) RF CHANNEL RELEASE ACK
20170425170133722 <0004> abis_rsl.c:1223 (bts=0,trx=0,ts=0,ss=1) state RELEASE REQUESTED -> NONE

#5 Updated by laforge 5 months ago

At about 70 EUR, the MC7504 from sierra wireless are among the more expensive options. One of their advantages is that they support USB-Audio profile, i.e. they should be usable for later extension towards voice testing.

The Gobi 2000 or Gobi 3000 modules are very cheap (<= 20 EUR), so we could buy them in quantity and have many more modems without effort.

EC20 / EC25 are somewhat in between. One of their advantages is that we can access (and hack/modify) the Linux running inside the device, which may come handy for further debugging or even making voice work.

In order to be on the safe side, I will order 5 more MC7504. So if this is the only type we can make work reliably now, we could assemble them into the quad modem boad currently in use (and also have some spare for use in another board/setup).

#6 Updated by laforge 5 months ago

#7 Updated by neels 5 months ago

  • Priority changed from Normal to Low

The sierra supporting the things tested now, it is low priority to get the others to work.
With 5 more ordered, we'll have 6 sierra modems. It will suffice to have 3 sierra in the R&D setup and the other 3 in the production rack.
We have yet to come up with a test case using more than two modems anyway.

#8 Updated by mschramm 5 months ago

  • Priority changed from Low to Normal

neels requested changing the modems in current QMOD test setup to

  • 3x SierraWireless AirPrime MC7304 and
  • 1x Quectel EC20

This is done, and as this is the configuration you guys wanted to have (before we can deploy more modem types), I'll leave the QMOD tester untouched; all tables, logs etc. should refer to this configuration.

#9 Updated by mschramm 5 months ago

  • Priority changed from Normal to Low

(sry - unintended prio change reversed)

#10 Updated by neels 5 months ago

  • Related to Bug #2237: ofono: Gobi modem: successful SMS delivery is evaluated as not successful added

#11 Updated by pespin 22 days ago

I think this issue is too generic and we can close it. We can better track (and we are already doing so) each issue separately. @lynxis do you agree?

Also available in: Atom PDF