Difference between revisions of "Debug log"
From Zenitel Wiki
(→Resource Allocation) |
(→Conversation) |
||
Line 76: | Line 76: | ||
An unused conversation channel receives a M PRES signal. This could occur if an remote node is out of sync with active AlphaNet connection, reset of own node... | An unused conversation channel receives a M PRES signal. This could occur if an remote node is out of sync with active AlphaNet connection, reset of own node... | ||
+ | |||
+ | E(110.65) ERR_IN_TST, no:23 TH#605 sent TONE_END_RCTRL to CONN#3 state SDCONN/WaitB_Timeout_TH (8)"TstErrFun1" P1: 3004, P2: 1131282432, P3: 0 | ||
+ | |||
+ | :P1: module * 1000 + code <br> | ||
+ | *module = 3, Message sending | ||
+ | *code = 4, Undefined process | ||
+ | Internal process signaling failed. An acknowledge for turning off tone in a conversation was received after the conversation ended.<br> | ||
=Subscriber key signaling= | =Subscriber key signaling= |
Revision as of 02:37, 16 March 2012
Description of some of the messages found in the debug log.
Most of the generated debug messages relates to the structure of the software of the AMC, the SDL and C-code itself. For example there are 74 SDL state machines with approx 3000 states able to send more than 2000 different signals to each other. If any state machine send signal X to another state machine which has not a handle for signal X in its current state an “UNEXP_SIG” or "UNEXP_SWITCH" message is generated telling the name of the signal, the sender and the receive state. This is handy when debugging the code but no easy to describe in beforehand since the system itself gives several million possibilities and ideally should not occur.
Contents
Directory Table
W(1.65) ERR_NVRAM, no:26 "CTNS_GPDH2" P1: 0, P2: 29, P3: 863
An element in the directory tables internal hash fast lookup table has a wrong value.
(The directory table sorting system (TNS) will be triggered for rebuilding)
W(1.65) TNS_VERIFY, no:34 "CTNS_V_NOW" P1: 0, P2: 0, P3: 0
The directory table sorting system is triggered for verification/rebuild (Verify Now) .
W(1.65) TNS_VERIFY, no:35 "CTNS_REGEN" P1: 0, P2: 0, P3: 0
The directory table sorting system is regenerated.
W(1.65) ERR_NVRAM, no:5564 "CTNS_NUM_1" P1: 25, P2: 65535, P3: 5
There are some corrupted elements in the directory table.
- P1: = First error element, referes to the internal tns structure. (nvram .ex_tns.tab[9637])
- P2: = Error type of first fault, 65535 = Directory number without number (empty number).
- P3: = Number of faults found. <nr>
Data Protocol
E(1.65) UNEXP_SWITCH, no:27 "DplcSndMsg" P1: 7, P2: 1, P3: 0
- P1: = Link number (ACDP link)
- P2: = Link address (Device number)
The ACDP link is not operational thus no message could be sent.
INFO_DPMR_NO_ROUTE, no:1279 CSI#1 sent READY to CSI#1 state CSI/ReadingCommands (3)"" P1: 1, P2: 62, P3: 0 Packet to node 1 device 62 dropped, no routing information
The routing to node 1 device 62 is not available.
(Typically after reset before the links are up, or due to no configuration of the route to node/device)
(1.65) ILLEGAL_PAR, no:56440 DP#11 sent DP_ANALYSE_MSG to DP#1 state DP/Operating (1)"DpTypNoAdd" P1: 160, P2: 1, P3: 13 (1.65) ILLEGAL_PAR, no:56441 DP#11 sent DP_ANALYSE_MSG to DP#1 state DP/Operating (1)"DpIllAdr" P1: 137, P2: 65, P3: 6
Illegal Message type or message parameter fault. Two error messages are reported to include 6 parameters with information.
Parameters:
- "DpTypNoAdd"
- P1:160 = Message type 0xA0 DIP_FWD
- P2:1 = Parameter number with error (Not relevant in this example)
- P3:13 = Value of the parameter (Not relevant in this example)
- "DpIllAdr"
- P1:137 = Message reference of the header of message.
- P2:65 = Device ID of the sender
- P3:6 = Node number of the sender
Reason for this example message:
DIP_FWD is not defined in older nodes.
This DIP_FWD message error can be produced in AlphaNet audio setup when nodes have different software versions. For later AlphaSys version the software version of other nodes will be checked before sending the "DIP_FWD" message to avoid error messages from older nodes.
Conversation
E(1.65) UNEXP_SIG, no:5285 TF#1 sent SW_ERR_TIMER to SCM#125 state SCM/PendingDiscon (19)"SCMSwErr" P1: 0, P2: 5, P3: 0
A conversation is disconnected, the call process awaits acknowledge for the cancellation from the subscriber processes.
Acknowledge is not received within timeout, a sw error timer will clean up the conversation.
- P1: Station 2 of the conversation
- P2: Station 1 of the conversation
When station = 0 it has acknowledge. Thus in this case station 5 has not sent acknowledge.
W(1.65) UNEXP_SIG, no:4413 CONN#2 sent ST_M_PRES to SCM#189 state SCM/DuplSimplMPres1 (3)"SCMdsmp1" P1: 0, P2: 0, P3: 0
Conversation
M Pres received from a station that already have the status of "M-PRES".
(M from $DP or event handler?)
E(1.65) UNEXP_SIG, no:6222 TF#1 sent MKEY_TIMER to SCM#172 state SCM/IPIPOpenSimplMRel (9)"SCM200" P1: 0, P2: 0, P3: 0
An conversation between two IP stations in M-key controlled simplex. A timing situation occur where both stations uses "M" is not handled correctly. Fixed for 11.2.3.4.
E(1.65) UNEXP_SIG, no:5519 SCM#213 sent ST_M_PRES to SCM#213 state SCM/NotInUse (1)"SCM200" P1: 0, P2: 0, P3: 0
An unused conversation channel receives a M PRES signal. This could occur if an remote node is out of sync with active AlphaNet connection, reset of own node...
E(110.65) ERR_IN_TST, no:23 TH#605 sent TONE_END_RCTRL to CONN#3 state SDCONN/WaitB_Timeout_TH (8)"TstErrFun1" P1: 3004, P2: 1131282432, P3: 0
- P1: module * 1000 + code
- module = 3, Message sending
- code = 4, Undefined process
Internal process signaling failed. An acknowledge for turning off tone in a conversation was received after the conversation ended.
Subscriber key signaling
E(1.65) UNEXP_SIG, no:1281 SBS#30 sent M_PRES_SBS to SBS#30 state SBS/IdleOnHook (14)"SBS010" P1: 0, P2: 0, P3: 0
Relates to physical station 30.
The signal M_PRES_SBS is used during active states of a subscriber. (Active in features like a call)
Since the station now is "IdleOnHook" probably the station just came back from an active state and received this signal delayed.
Maybe event handler or $DP signaled M pres?
E(1.65) UNEXP_SIG, no:6 TO_IF#1 sent KEY_PRES to SBS#30 state SBS/NoSLI (1)"SBS010" P1: 0, P2: 0, P3: 0 (1)"SBS010" P1: 0, P2: 0, P3: 0 E(1.65) UNEXP_SIG, no:87 TO_IF#1 sent KEY_REL to SBS#30 state SBS/NoSLI (1)"SBS010" P1: 0, P2: 0, P3: 0 (1)"SBS010" P1: 0, P2: 0, P3: 0
Relates to physical station 30.
The station is in state "No subscriber line interface", this means not connected/registered or not found jet (ASLT scanning after reset.)
The station receives a KEY PRES/KEY RELEASE signal, this should not be possible unless the signal comes from event handler or $DP signaled key pres.
E(1.65) UNEXP_SIG, no:5714 UNDEFINED PROCESS#0 sent KEY_PRES to SBS#30 state SBS/NoSLI (1)"SBS010" P1: 0, P2: 0, P3: 0
E(1.65) UNEXP_SIG, no:5716 UNDEFINED PROCESS#0 sent KEY_REL to SBS#30 state SBS/NoSLI (1)"SBS010" P1: 0, P2: 0, P3: 0
Same as above but probably early in restart of AlphaCom thus not all processes have been initiated jet.
E(1.65) UNEXP_SIG, no:5512 DP#1 sent C_PRES to SBS#37 state SBS/NoSLI (1)"SBS010" P1: 0, P2: 0, P3: 0
E(1.65) UNEXP_SIG, no:5513 DP#1 sent C_REL to SBS#37 state SBS/NoSLI (1)"SBS010" P1: 0, P2: 0, P3: 0
Relates to physical station 37.
C PRES / RELEASE signaling are coming from data protocol to a station not connected/registred.
E(1.65) UNEXP_SIG, no:7 DP#1 sent M_PRES to SBS#30 state SBS/NoSLI (1)"SBS010" P1: 0, P2: 0, P3: 0
Relates to physical station 30.
The station is in state "No subscriber line interface", this means not connected/registered or not found jet after reset.
The station receives a M_PRES signal from date protocol. I.e. from Event Handler or ACDP.
E(1.65) UNEXP_SWITCH, no:4817 TH#40 sent TONE_END_RCTRL to SBS#40 state SDACTIV/ADC_FeatToneStop (67)"SbsSbsFeat" P1: 22, P2: 0, P3: 0
Physical station 40.
Feature activated (during conversation) the feature dialed was not allowed in this situation.
- P1: Feature number. (22 = Microphone Mute)
W(1.65) APR_INVAL_NEXT_NODE, no:5993 SCM#80 sent PROCEED to SCM#80 state SDAPR/AudioPathStartWaitRoute (2)"Route0" P1: 2, P2: 0, P3: 1 Invalid next audio node from own node 1 to destination node 2
No available data or audio route found to next node. Could be node down.
Other Subscriber signaling
E(1.65) UNEXP_SIG, no:5916 SBS#30 sent SBS_DISCON to SBS#30 state SBS/StationActive (56)"SBS010" P1: 0, P2: 0, P3: 0
Relates to station 30.
The station has just left active state and a delayed "disconnect" signal only used in the active state is received.
This signal should just be ignored. Fixed for 11.2.3.4
License string
W(1.65) TABLE, no:57 "CipherErr" P1: 0, P2: 0, P3: 0
If no legal license key is present in the system <br\>
Corrupted license string.
System without license string
Could be wrong license MAC address.
Issues with reading own MAC address?
RCI - RCO
There where made RCI/RCO related fixes 11.2.3.2.
- Multi Drop Master protocol
- RCO timers where made individual.
- New flag for automatically sync of RCI state ON/OFF when RIO/MIO reports states out of the AMC expected order. .ex_profile.flags.RCI_sync = 0
RCI
W(1.65) UNEXP_SIG, no:36262 DP#1 sent SCAN_RCI_ACK to RCI#51 state RCI/WaitResp (8)"sRCI010" P1: 0, P2: 0, P3: 0
Relate to logical RCI 51.
The input device (RIO/MIO) is sending $SCAN_RCI_ACK in a state where $RCI_IS_ON or $RCI_IS_OFF is expected.
Last signal received before this state was $SCAN_RCI_ACK, thus it looks like double signaling.
W(1.65) UNEXP_SIG, no:257 DP#1 sent SCAN_RCI_ACK to RCI#71 state RCI/WaitRespAlarm (14)"sRCI010" P1: 0, P2: 0, P3: 0
Relates to RCI 71.
The RCI is active, expected signal is RCI_ON or RCI_OFF (dependent on the polarity setting).
Instead SCAN_RCI_ACK is received.
W(1.65) UNEXP_SWITCH, no:4999 DP#1 sent RCI_IS_OFF to RCI#71 state RCI/WaitRespAlarm (14)"RciOfPolar" P1: 0, P2: 0, P3: 0
Relates to RCI 71
The RCI is currently OFF, only new legal state is RCI_IS_ON. The RIO/MIO is reporting state RCI_IS_OFF. (With the flag RCI_sync = 1 this will be resolved)
W(1.65) UNEXP_SIG, no:5566 DP#1 sent RCI_IS_OFF to RCI#72 state RCI/Pending (3)"sRCI010" P1: 0, P2: 0, P3: 0 W(1.65) UNEXP_SIG, no:5567 DP#1 sent RCI_IS_ON to RCI#72 state RCI/Pending (3)"sRCI010" P1: 0, P2: 0, P3: 0
Relates to RCI 72.
The RCI is in state Pending, it means the MIO/RIO device has not been reported up jet. Since the device is not available no state changes are accepted. (RCI ON/OFF is reported from the device)
RCO
W(1.65) UNEXP_SWITCH, no:65294 DP#1 sent CLEAR_RCO_ACK to RCO#1 state RCO/Running (1)"RcoUnexp" P1: 7, P2: 0, P3: 0.
- P1: RCO number 7
Unexpected CLEAR_RCO_ACK from RIO/MIO, (no pending ACK for this RCO). Could it be resending of CLEAR_RCO_ACK?
W(1.65) UNEXP_SWITCH, no:5284 DP#1 sent CLEAR_RCO_ACK to RCO#1 state RCO/Running (1)"RcoPolarit" P1: 22, P2: 0, P3: 0
- P1: RCO number 22
There is a pending acknowledge for this RCO but it should be SET_RCO_ACK not CLEAR_RCO_ACK.
W(1.65) UNEXP_SWITCH, no:10429 DP#1 sent SET_RCO_ACK to RCO#1 state RCO/Running (1)"RcoPolarit" P1: 8, P2: 0, P3: 0
Relates to RCO 7 (P1)
unexpected SET_RCO_ACK from RIO/MIO, (no pending ACK for this RCO). Could it be resending of SET_RCO_ACK?
W(1.65) UNEXP_SWITCH, no:59970 DP#1 sent SET_RCO_ACK to RCO#1 state RCO/Running (1)"RcoNoMatch" P1: 137, P2: 2, P3: 2 W(1.65) UNEXP_SWITCH, no:59971 DP#1 sent CLEAR_RCO_ACK to RCO#1 state RCO/Running (1)"RcoNoMatch" P1: 137, P2: 2, P3: 2
The RCO is not found in the configuration
- P1 = Logical RCO number
- P2 = Device number
- P3 = Pin number (on the device)
Conference
E(1.65) ILLEGAL_PAR, no:39413 SPF#30 sent ST_TALK_STOP to CNF#5 state CNF/Operating (1)"CnfTalkSto" P1: 30, P2: 0, P3: 0
Physical station 30 was asked to stop talking in conference 5, but no one was talking in the conference.
- P1 = New Talker To stop
- P2 = Current talker
E(1.65) UNEXP_SIG, no:39414 SPF#30 sent DP_TALK_END_RCTRL to SBS#30 state SBS/IdleOnHook (14)"SBS010" P1: 0, P2: 0, P3: 0
This is a result of the "CnfTalkSto" error message.
Conference 5 was replying to the "stop talking message" but subscriber 30 was not talking, "IdleOnHook".
E(1.65) UNEXP_SIG, no:41065 SPF#37 sent DP_TALK_SUCCESS to SBS#37 state SBS/GoActiveKeyPres (52)"SBS010" P1: 0, P2: 0, P3: 0
Station 37 entered talk mode in a conference at the same moment as a key pres was activated on the station.
This resulted in the acknowledge message "DP_TALK_SUCCESS" from the conference was received in a transit state for activating the station because of key pres.
E(1.65) UNEXP_SIG, no:41068 SPF#37 sent CONFERENCE_MODE to SBS#37 state SBS/ConfGoTalk (76)"SBS010" P1: 0, P2: 0, P3: 0
Station 37 is entering talk mode in a conference and at the same time receives a signal for entering conference mode.
The subscriber and the conference seams to be out of sync, or $DP conference messages are interfering the internal state changes of the station
E(1.65) UNEXP_SIG, no:5278 SPF#40 sent CONFERENCE_MODE to SBS#40 state SBS/NoSLI (1)"SBS010" P1: 0, P2: 0, P3: 0
Station 40 is asked to join a conference, but the station is not registered or connected.
E(1.65) UNEXP_SIG, no:21354 SPF#30 sent NORMAL_MODE to SBS#30 state SBS/IdleOnHook (14)"SBS010" P1: 0, P2: 0, P3: 0
Physical station 30 is asked to leave conference mode and return to idle, but the station is already in idle.
(Conference and station mismatch in state, $DP messages?)
E(1.65) UNEXP_SIG, no:4848 SPF#37 sent NORMAL_MODE to SBS#37 state SBS/ConfTalkBusy (79)"SBS010" P1: 0, P2: 0, P3: 0
Related to physical station 37.
Station tries to talk in to a conference (M-pres) but the station is rejected from talk because an other talker is active. In this state the station is asked to disconnect from the conference ("NORMAL MODE"). (This message could occur if an Alarm message or program with volume override is started, due to the more "brutal" way of forcing the station.)
IP Station
W(1.65) TABLE, no:5811 "NoPong" P1: 121, P2: 0, P3: 0
- P1: IP station physical number.
The IP station application has not replied to a PING messages. The IP socket to the station is terminated.
W(1.65) TABLE, no:197 "SockFail" P1: 32, P2: 0, P3: 0
- P1: IP station physical number.
IP station socket for data communication is closed but the IP station state in AlphaCom is still "UP".
(Checked approx every 5 minute, and station reported down)
E(1.65) UNEXP_SIG, no:5331 TF#1 sent IP_ST_TIMER to IP_ST#30 state IP_ST/connected (1)"NO_RTP" P1: 0, P2: 0, P3: 0
IP station physical number 30 should send RTP audio to AMCd but nothing is received.
Event Handler
W(1.65) UNEXP_SIG, no:3237 CSI#1 sent CSI_ERROR to EVH#1 state EVH/Idle (1)"sEVH020" P1: 228, P2: 0, P3: 0
- P1 Character position of the fault
There is a fault in an Event Script. The system log contains more related information:
syntax error in Event (15)EvntTri.6a on owner sta 30 : before char# 228 in string : "IF %op(%op(%2d,>=,5331),&,%op(%2d, <=,5340));@00FF $RCIC W%sev U%3c(%2d(1),0);IF %3c(1,0);IF %op(%op(%sev,>=,101),&,%op(%sev,<=,108));@01FF M7F00 %1.ref U5 W0 "Störungen" U1;endif;endif;IF %op(%sev,>,1"
Resource Allocation
D(1.65) ERR_ASSERT, no:5711 SBS#30 sent ST_RELEASE to SBA#1 state SBA/Operating (1)"sSBA070"
Relates to station 30
The station was released from busy state (Feature, handset off++) but the station has not status of allocated in the subscriber allocator...