Hello,
I've run into an problem with ARQ sessions with a connection bandwidth of 200. Although in these cases the connection is established, the subsequent transfer of data frames between the stations is severely degraded. Zero, one or two data frames are transferred, then the process stalls until l the connection times out. I often see in the exception log of the server station a stream of these:
02:49:10.942 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
This is true only for a requested connection bandwidth of 200. The strange thing is that with exactly the same hardware and software setup, ARQ connections with a bandwidth of 500 or 2500 work fine, whether negotiation is used or not. Here's a table:
Client 2500 --> Server 2500 good
Client 500 --> Server 2500 good (negotiatebw=true of necessity)
Client 200 --> Server 2500 bad (negotiatebw=true of necessity)
Client 500 --> Server 500 good
Client 200 --> Server 500 bad (negotiatebw=true of necessity)
Client 200 --> Server 200 bad
This is repeatable here, in a test bed consisting of 2 Win10 (v1709) PCs running ARDOP_2Win 2.0.4 and ARIM 2.1, connected by 2 back-to-back USB sound cards. Connections are established and then a file listing request is made by one station to the other (it fails either way).
Below are debug and exception log excerpts from client and server TNCs for a typical case where bw=200. Immediately thereafter, success is achieved if I simply switch to a configuration using arqbw 500 or 2500, or a combination thereof, by issuing the ARQBW command to the TNCs with the new values.
Is any one else having trouble like this? I'll be happy to do more testing and send logs as time permits.
73,
Bob NW8L
Client station debug log
====================
02:48:50.114 [2.0.4] [GenerateSessionID] Caller=NW8L, Target=KA8RYU ID= H11
02:48:50.119 [2.0.4] [SetARDOPProtocolState] New State=ISS
02:48:50.119 [2.0.4] [Main.SendFrame] Send ConReq200: NW8L > KA8RYU delayed 100 ms
02:48:50.119 [2.0.4] [GenerateSessionID] Caller=NW8L, Target=KA8RYU ID= H11
02:48:50.119 [2.0.4] [SendARQConnectRequest] strMycall=NW8L strTargetCall=KA8RYU bytPendingSessionID=H11
02:48:50.135 [2.0.4] ToolStripLatency.Text = Latency Calculation
02:48:50.235 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 16 ms
02:48:50.235 [2.0.4] [Main.KeyPTT] True
02:48:50.235 [2.0.4] [PlaySoundStream] ConReq200: NW8L > KA8RYU
02:48:50.235 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:48:51.314 [2.0.4] [MainPoll] Play stop. Length = 1079 ms
02:48:51.352 [2.0.4] [Main.KeyPTT] False
02:48:51.352 [2.0.4] GetNextARQFrame intPingRpt=0
02:48:51.352 [2.0.4] [Main.tmrPoll] Frame Pending
02:48:51.494 [2.0.4] Timeout in T>R Latency calculation
02:48:51.518 [2.0.4] ToolStripLatency.Text = Latency Measure Timeout
02:48:51.835 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:48:51.995 [2.0.4] [Frame Type OK]5 ConAck, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=29.5dB, Offset=0.00Hz
02:48:51.996 [2.0.4] [DecodeFrame] Frame: ConAck PASS, Quality= 96 bytes= 0
02:48:51.996 [2.0.4] [ARDOPprotocol.ProcessRcvdARQFrame] ISS Measured RoundTrip = 302 ms
02:48:52.004 [2.0.4] [Main.SendFrame] Send IDFrame_NW8L [EN68] delayed 100 ms
02:48:52.004 [2.0.4] [ARDOPprotocol.ProcessRcvdARQFrame] Compatible bandwidth received from IRS ConAck: 200 Hz
02:48:52.044 [2.0.4] ToolStripLatency.Text = Session Thruput
02:48:52.132 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 28 ms
02:48:52.133 [2.0.4] [Main.KeyPTT] True
02:48:52.135 [2.0.4] [PlaySoundStream] IDFrame_NW8L [EN68]
02:48:52.135 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:48:53.819 [2.0.4] [MainPoll] Play stop. Length = 1684 ms
02:48:53.852 [2.0.4] [Main.KeyPTT] False
02:48:53.852 [2.0.4] GetNextARQFrame intPingRpt=0
02:48:53.852 [2.0.4] [Main.tmrPoll] Frame Pending
02:48:54.375 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:48:54.566 [2.0.4] [Frame Type OK]5 DataACK, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=30.5dB, Offset=0.00Hz
02:48:54.567 [2.0.4] [DecodeFrame] Frame: DataACK PASS, Quality= 98 bytes= 0
02:48:54.568 [2.0.4] [ARDOPprotocol.ProcessRcvdARQFrame] ACK to IDFrame received in ARQState ISSConReq with DataToSend = 0
02:48:54.568 [2.0.4] [SetARDOPProtocolState] New State=IDLE
02:48:54.570 [2.0.4] [Main.SendFrame] Send IDLE delayed 100 ms
02:48:54.685 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=IDLE blnFramePending=True next Play in 15 ms
02:48:54.685 [2.0.4] [Main.KeyPTT] True
02:48:54.686 [2.0.4] [PlaySoundStream] IDLE
02:48:54.686 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:48:55.117 [2.0.4] [MainPoll] Play stop. Length = 431 ms
02:48:55.149 [2.0.4] [Main.KeyPTT] False
02:48:55.149 [2.0.4] GetNextARQFrame intPingRpt=0
02:48:55.149 [2.0.4] [Main.tmrPoll] Frame Pending
02:48:55.755 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:48:55.847 [2.0.4] [Frame Type OK]9 DataACK, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=30.5dB, Offset=0.00Hz
02:48:55.945 [2.0.4] [DecodeFrame] Frame: DataACK PASS, Quality= 98 bytes= 0
02:48:57.202 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=IDLE blnFramePending=True next Play in 53 ms
02:48:57.203 [2.0.4] [Main.KeyPTT] True
02:48:57.204 [2.0.4] [PlaySoundStream] IDLE
02:48:57.204 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:48:57.633 [2.0.4] [MainPoll] Play stop. Length = 429 ms
02:48:57.669 [2.0.4] [Main.KeyPTT] False
02:48:57.669 [2.0.4] GetNextARQFrame intPingRpt=0
02:48:57.669 [2.0.4] [Main.tmrPoll] Frame Pending
02:48:58.235 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:48:58.326 [2.0.4] [Frame Type OK]9 DataACK, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=28.8dB, Offset=0.00Hz
02:48:58.396 [2.0.4] [DecodeFrame] Frame: DataACK PASS, Quality= 98 bytes= 0
02:48:59.719 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=IDLE blnFramePending=True next Play in 50 ms
02:48:59.720 [2.0.4] [Main.KeyPTT] True
02:48:59.721 [2.0.4] [PlaySoundStream] IDLE
02:48:59.721 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:00.118 [2.0.4] [MainPoll] Play stop. Length = 398 ms
02:49:00.154 [2.0.4] [Main.KeyPTT] False
02:49:00.154 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:00.154 [2.0.4] [Main.tmrPoll] Frame Pending
02:49:00.715 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:00.875 [2.0.4] [Frame Type OK]9 DataACK, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=33.1dB, Offset=0.00Hz
02:49:00.876 [2.0.4] [DecodeFrame] Frame: DataACK PASS, Quality= 98 bytes= 0
02:49:00.876 [2.0.4] [ARDOPprotocol.ProcessedRcvdARQFrame] Protocol state IDLE, ACK Received with Data to send. Go to ISS Data state.
02:49:00.877 [2.0.4] [SetARDOPProtocolState] New State=ISS
02:49:00.877 [2.0.4] Temp[ARDOPprotocol.ProcessedRcvdARQFrame] No Initialization: bytCurrentFrameType = 16QAM.200.100.E
02:49:00.877 [2.0.4] [ARDOPprotocol.SendData] DataToSend = 8 bytes, In ProtocolState ISS
02:49:00.877 [2.0.4] [ARDOPprotocol.GetNextFrameData]2 Set bytFrameTypeToSend to 15
02:49:00.877 [2.0.4] [ARDOPprotocol.GetNextFrameData] No shift, Frame Type: 16QAM.200.100.O
02:49:00.877 [2.0.4] *** GetextFrameData Frame=16QAM.200.100.E DataLen=120 NumCar=1
02:49:00.877 [2.0.4] *** Call GetDatFromQueue[GetNextFrameData] 1 DataLen=120 bytes
02:49:00.927 [2.0.4] [Main.SendFrame] Send 16QAM.200.100.O delayed 100 ms
02:49:01.045 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 18 ms
02:49:01.046 [2.0.4] [Main.KeyPTT] True
02:49:01.048 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:49:01.048 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:04.752 [2.0.4] [MainPoll] Play stop. Length = 3704 ms
02:49:04.783 [2.0.4] [Main.KeyPTT] False
02:49:04.783 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:04.783 [2.0.4] [Main.tmrPoll] Frame Pending
02:49:06.311 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 28 ms
02:49:06.312 [2.0.4] [Main.KeyPTT] True
02:49:06.314 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:49:06.314 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:10.004 [2.0.4] [MainPoll] Play stop. Length = 3689 ms
02:49:10.038 [2.0.4] [Main.KeyPTT] False
02:49:10.038 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:10.038 [2.0.4] [Main.tmrPoll] Frame Pending
02:49:11.577 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 39 ms
02:49:11.578 [2.0.4] [Main.KeyPTT] True
02:49:11.580 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:49:11.580 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:15.300 [2.0.4] [MainPoll] Play stop. Length = 3721 ms
02:49:15.335 [2.0.4] [Main.KeyPTT] False
02:49:15.335 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:15.335 [2.0.4] [Main.tmrPoll] Frame Pending
02:49:16.848 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 13 ms
02:49:16.848 [2.0.4] [Main.KeyPTT] True
02:49:16.851 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:49:16.851 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:20.555 [2.0.4] [MainPoll] Play stop. Length = 3704 ms
02:49:20.592 [2.0.4] [Main.KeyPTT] False
02:49:20.592 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:20.592 [2.0.4] [Main.tmrPoll] Frame Pending
02:49:22.133 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 41 ms
02:49:22.134 [2.0.4] [Main.KeyPTT] True
02:49:22.137 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:49:22.137 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:25.829 [2.0.4] [MainPoll] Play stop. Length = 3691 ms
02:49:25.863 [2.0.4] [Main.KeyPTT] False
02:49:25.863 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:25.863 [2.0.4] [Main.tmrPoll] Frame Pending
02:49:27.421 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 59 ms
02:49:27.422 [2.0.4] [Main.KeyPTT] True
02:49:27.424 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:49:27.424 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:31.132 [2.0.4] [MainPoll] Play stop. Length = 3708 ms
02:49:31.161 [2.0.4] [Main.KeyPTT] False
02:49:31.161 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:31.161 [2.0.4] [Main.tmrPoll] Frame Pending
02:49:32.662 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 1 ms
02:49:32.663 [2.0.4] [Main.KeyPTT] True
02:49:32.665 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:49:32.665 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:36.357 [2.0.4] [MainPoll] Play stop. Length = 3691 ms
02:49:36.392 [2.0.4] [Main.KeyPTT] False
02:49:36.392 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:36.392 [2.0.4] [Main.tmrPoll] Frame Pending
02:49:37.901 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 9 ms
02:49:37.901 [2.0.4] [Main.KeyPTT] True
02:49:37.903 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:49:37.903 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:41.607 [2.0.4] [MainPoll] Play stop. Length = 3704 ms
02:49:41.641 [2.0.4] [Main.KeyPTT] False
02:49:41.641 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:41.641 [2.0.4] [Main.tmrPoll] Frame Pending
02:49:43.171 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 30 ms
02:49:43.172 [2.0.4] [Main.KeyPTT] True
02:49:43.174 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:49:43.174 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:46.880 [2.0.4] [MainPoll] Play stop. Length = 3706 ms
02:49:46.916 [2.0.4] [Main.KeyPTT] False
02:49:46.917 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:46.917 [2.0.4] [Main.tmrPoll] Frame Pending
02:49:48.440 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 24 ms
02:49:48.441 [2.0.4] [Main.KeyPTT] True
02:49:48.443 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:49:48.443 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:52.165 [2.0.4] [MainPoll] Play stop. Length = 3722 ms
02:49:52.201 [2.0.4] [Main.KeyPTT] False
02:49:52.202 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:52.202 [2.0.4] [Main.tmrPoll] Frame Pending
02:49:53.727 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 25 ms
02:49:53.728 [2.0.4] [Main.KeyPTT] True
02:49:53.730 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:49:53.730 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:57.454 [2.0.4] [MainPoll] Play stop. Length = 3724 ms
02:49:57.489 [2.0.4] [Main.KeyPTT] False
02:49:57.489 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:57.489 [2.0.4] [Main.tmrPoll] Frame Pending
02:49:59.030 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 41 ms
02:49:59.031 [2.0.4] [Main.KeyPTT] True
02:49:59.033 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:49:59.033 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:50:02.741 [2.0.4] [MainPoll] Play stop. Length = 3708 ms
02:50:02.775 [2.0.4] [Main.KeyPTT] False
02:50:02.775 [2.0.4] GetNextARQFrame intPingRpt=0
02:50:02.775 [2.0.4] [Main.tmrPoll] Frame Pending
02:50:04.321 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 45 ms
02:50:04.321 [2.0.4] [Main.KeyPTT] True
02:50:04.328 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:50:04.328 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:50:08.056 [2.0.4] [MainPoll] Play stop. Length = 3728 ms
02:50:08.090 [2.0.4] [Main.KeyPTT] False
02:50:08.090 [2.0.4] GetNextARQFrame intPingRpt=0
02:50:08.090 [2.0.4] [Main.tmrPoll] Frame Pending
02:50:09.635 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 45 ms
02:50:09.636 [2.0.4] [Main.KeyPTT] True
02:50:09.638 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:50:09.638 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:50:13.344 [2.0.4] [MainPoll] Play stop. Length = 3706 ms
02:50:13.379 [2.0.4] [Main.KeyPTT] False
02:50:13.379 [2.0.4] GetNextARQFrame intPingRpt=0
02:50:13.379 [2.0.4] [Main.tmrPoll] Frame Pending
02:50:14.891 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 12 ms
02:50:14.892 [2.0.4] [Main.KeyPTT] True
02:50:14.894 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:50:14.894 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:50:18.610 [2.0.4] [MainPoll] Play stop. Length = 3716 ms
02:50:18.645 [2.0.4] [Main.KeyPTT] False
02:50:18.645 [2.0.4] GetNextARQFrame intPingRpt=0
02:50:18.645 [2.0.4] [Main.tmrPoll] Frame Pending
02:50:20.156 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 11 ms
02:50:20.157 [2.0.4] [Main.KeyPTT] True
02:50:20.159 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:50:20.159 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:50:23.850 [2.0.4] [MainPoll] Play stop. Length = 3692 ms
02:50:23.883 [2.0.4] [Main.KeyPTT] False
02:50:23.883 [2.0.4] GetNextARQFrame intPingRpt=0
02:50:23.883 [2.0.4] [Main.tmrPoll] Frame Pending
02:50:25.397 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 14 ms
02:50:25.398 [2.0.4] [Main.KeyPTT] True
02:50:25.400 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:50:25.400 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:50:29.097 [2.0.4] [MainPoll] Play stop. Length = 3697 ms
02:50:29.124 [2.0.4] [Main.KeyPTT] False
02:50:29.124 [2.0.4] GetNextARQFrame intPingRpt=0
02:50:29.124 [2.0.4] [Main.tmrPoll] Frame Pending
02:50:30.629 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 5 ms
02:50:30.629 [2.0.4] [Main.KeyPTT] True
02:50:30.632 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:50:30.632 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:50:34.337 [2.0.4] [MainPoll] Play stop. Length = 3705 ms
02:50:34.366 [2.0.4] [Main.KeyPTT] False
02:50:34.366 [2.0.4] GetNextARQFrame intPingRpt=0
02:50:34.366 [2.0.4] [Main.tmrPoll] Frame Pending
02:50:35.883 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 17 ms
02:50:35.884 [2.0.4] [Main.KeyPTT] True
02:50:35.886 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:50:35.886 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:50:39.580 [2.0.4] [MainPoll] Play stop. Length = 3695 ms
02:50:39.615 [2.0.4] [Main.KeyPTT] False
02:50:39.615 [2.0.4] GetNextARQFrame intPingRpt=0
02:50:39.615 [2.0.4] [Main.tmrPoll] Frame Pending
02:50:41.160 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 45 ms
02:50:41.161 [2.0.4] [Main.KeyPTT] True
02:50:41.163 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:50:41.163 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:50:44.876 [2.0.4] [MainPoll] Play stop. Length = 3713 ms
02:50:44.911 [2.0.4] [Main.KeyPTT] False
02:50:44.911 [2.0.4] GetNextARQFrame intPingRpt=0
02:50:44.911 [2.0.4] [Main.tmrPoll] Frame Pending
02:50:46.438 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 27 ms
02:50:46.439 [2.0.4] [Main.KeyPTT] True
02:50:46.441 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:50:46.441 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:50:50.128 [2.0.4] [MainPoll] Play stop. Length = 3687 ms
02:50:50.163 [2.0.4] [Main.KeyPTT] False
02:50:50.163 [2.0.4] GetNextARQFrame intPingRpt=0
02:50:50.163 [2.0.4] [Main.tmrPoll] Frame Pending
02:50:51.689 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 26 ms
02:50:51.689 [2.0.4] [Main.KeyPTT] True
02:50:51.692 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:50:51.692 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:50:55.396 [2.0.4] [MainPoll] Play stop. Length = 3704 ms
02:50:55.434 [2.0.4] [Main.KeyPTT] False
02:50:55.434 [2.0.4] GetNextARQFrame intPingRpt=0
02:50:55.434 [2.0.4] [Main.tmrPoll] Frame Pending
02:50:56.964 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 30 ms
02:50:56.965 [2.0.4] [Main.KeyPTT] True
02:50:56.967 [2.0.4] [PlaySoundStream] 16QAM.200.100.O
02:50:56.967 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:51:00.686 [2.0.4] [MainPoll] Play stop. Length = 3719 ms
02:51:00.720 [2.0.4] [Main.KeyPTT] False
02:51:00.720 [2.0.4] GetNextARQFrame intPingRpt=0
02:51:00.720 [2.0.4] [Main.tmrPoll] Frame Pending
02:51:00.964 [2.0.4] [ARDOPprotocol.PollARQTimeout] Timeout setting SendTimeout timer to start.
02:51:01.072 [2.0.4] ARDOPprotocol.tmrSendTimeout] ARQ Timeout from ProtocolState: ISS Going to DISC state
02:51:01.080 [2.0.4] [Main.SendFrame] Send IDFrame_NW8L [EN68] delayed 100 ms
02:51:01.196 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=ISS blnFramePending=True next Play in 17 ms
02:51:01.196 [2.0.4] [Main.KeyPTT] True
02:51:01.197 [2.0.4] [PlaySoundStream] IDFrame_NW8L [EN68]
02:51:01.197 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:51:01.537 [2.0.4] [SetARDOPProtocolState] New State=DISC
02:51:02.879 [2.0.4] [MainPoll] Play stop. Length = 1681 ms
02:51:02.914 [2.0.4] [Main.KeyPTT] False
02:51:03.298 [2.0.4] [Main.SendFrame] Send DISC delayed 100 ms
02:51:03.420 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=DISC blnFramePending=True next Play in 23 ms
02:51:03.421 [2.0.4] [Main.KeyPTT] True
02:51:03.422 [2.0.4] [PlaySoundStream] DISC
02:51:03.422 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:51:03.854 [2.0.4] [MainPoll] Play stop. Length = 433 ms
02:51:03.888 [2.0.4] [Main.KeyPTT] False
02:51:05.454 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:51:05.635 [2.0.4] [Frame Type OK]2 IDFrame, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=30.8dB, Offset=0.00Hz
02:51:06.919 [2.0.4] [DecodeFrame] Frame: IDFrame PASS, Quality= 89 bytes= 18
02:51:07.663 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:51:07.834 [2.0.4] [Frame Type OK]1 DISC, D1=.00, D3=.00 Ldr; S:N(3KHz) Avg=33.5dB, Offset=0.00Hz
02:51:07.836 [2.0.4] [DecodeFrame] Frame: DISC PASS, Quality= 97 bytes= 0
Server station debug log
====================
02:48:51.335 [2.0.4] Command Trace TO Host: BUSY TRUE
02:48:51.476 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:48:51.667 [2.0.4] [Frame Type OK]1 ConReq200, D1=.00, Parity of ID1 OK
02:48:51.667 [2.0.4] Command Trace TO Host: PENDING
02:48:51.925 [2.0.4] Command Trace from HOST: PROTOCOLMODE ARQ
02:48:51.926 [2.0.4] Command Trace TO Host: PROTOCOLMODE NOW ARQ
02:48:52.239 [2.0.4] [DecodeFrame] Frame: ConReq200 PASS, Quality= 87 bytes= 7
02:48:52.239 [2.0.4] [ProcessRcvdARQFrame]1 ConReq200 bytSessionID=11
02:48:52.239 [2.0.4] Command Trace TO Host: TARGET KA8RYU
02:48:52.240 [2.0.4] Command Trace TO Host: NEWSTATE IRS
02:48:52.240 [2.0.4] [SetARDOPProtocolState] New State=IRS
02:48:52.242 [2.0.4] [Main.SendFrame] Send ConAck delayed 100 ms
02:48:52.283 [2.0.4] ToolStripLatency.Text = Session Thruput
02:48:52.377 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=IRS blnFramePending=True next Play in 36 ms
02:48:52.377 [2.0.4] Command Trace TO Host: PTT TRUE
02:48:52.377 [2.0.4] [Main.KeyPTT] True
02:48:52.378 [2.0.4] [PlaySoundStream] ConAck
02:48:52.378 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:48:52.803 [2.0.4] [MainPoll] Play stop. Length = 425 ms
02:48:52.835 [2.0.4] Command Trace TO Host: PTT FALSE
02:48:52.835 [2.0.4] [Main.KeyPTT] False
02:48:52.835 [2.0.4] GetNextARQFrame intPingRpt=0
02:48:53.367 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:48:53.527 [2.0.4] [Frame Type OK]5 IDFrame, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=33.9dB, Offset=0.00Hz
02:48:54.811 [2.0.4] [DecodeFrame] Frame: IDFrame PASS, Quality= 83 bytes= 16
02:48:54.813 [2.0.4] [Main.SendFrame] Send DataACK delayed 100 ms
02:48:54.813 [2.0.4] Command Trace TO Host: CONNECTED NW8L 200 [EN68]
02:48:54.813 [2.0.4] Command Trace TO Host: STATUS ARQ CONNECTION ESTABLISHED WITH NW8L,BW=200,GS=[EN68]
02:48:54.939 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=IRS blnFramePending=True next Play in 27 ms
02:48:54.939 [2.0.4] Command Trace TO Host: PTT TRUE
02:48:54.939 [2.0.4] [Main.KeyPTT] True
02:48:54.940 [2.0.4] [PlaySoundStream] DataACK
02:48:54.941 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:48:55.366 [2.0.4] [MainPoll] Play stop. Length = 425 ms
02:48:55.403 [2.0.4] Command Trace TO Host: PTT FALSE
02:48:55.403 [2.0.4] [Main.KeyPTT] False
02:48:55.404 [2.0.4] GetNextARQFrame intPingRpt=0
02:48:55.936 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:48:56.097 [2.0.4] [Frame Type OK]9 IDLE, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=27.8dB, Offset=0.00Hz
02:48:56.098 [2.0.4] [DecodeFrame] Frame: IDLE PASS, Quality= 96 bytes= 0
02:48:56.098 [2.0.4] [ARDOPprotocol.ProcessRcvdARQFrame] IDLE received in ProtocolState IRS, substate: IRSData
02:48:56.100 [2.0.4] [Main.SendFrame] Send DataACK delayed 100 ms
02:48:56.236 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=IRS blnFramePending=True next Play in 36 ms
02:48:56.236 [2.0.4] Command Trace TO Host: PTT TRUE
02:48:56.236 [2.0.4] [Main.KeyPTT] True
02:48:56.237 [2.0.4] [PlaySoundStream] DataACK
02:48:56.237 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:48:56.658 [2.0.4] [MainPoll] Play stop. Length = 422 ms
02:48:56.697 [2.0.4] Command Trace TO Host: PTT FALSE
02:48:56.697 [2.0.4] [Main.KeyPTT] False
02:48:56.697 [2.0.4] GetNextARQFrame intPingRpt=0
02:48:58.387 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:48:58.577 [2.0.4] [Frame Type OK]9 IDLE, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=31.1dB, Offset=0.00Hz
02:48:58.578 [2.0.4] [DecodeFrame] Frame: IDLE PASS, Quality= 96 bytes= 0
02:48:58.578 [2.0.4] [ARDOPprotocol.ProcessRcvdARQFrame] IDLE received in ProtocolState IRS, substate: IRSData
02:48:58.580 [2.0.4] [Main.SendFrame] Send DataACK delayed 100 ms
02:48:58.704 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=IRS blnFramePending=True next Play in 25 ms
02:48:58.705 [2.0.4] Command Trace TO Host: PTT TRUE
02:48:58.705 [2.0.4] [Main.KeyPTT] True
02:48:58.706 [2.0.4] [PlaySoundStream] DataACK
02:48:58.706 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:48:59.129 [2.0.4] [MainPoll] Play stop. Length = 423 ms
02:48:59.160 [2.0.4] Command Trace TO Host: PTT FALSE
02:48:59.160 [2.0.4] [Main.KeyPTT] False
02:48:59.160 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:00.967 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:01.117 [2.0.4] [Frame Type OK]9 IDLE, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=28.9dB, Offset=0.00Hz
02:49:01.118 [2.0.4] [DecodeFrame] Frame: IDLE PASS, Quality= 96 bytes= 0
02:49:01.118 [2.0.4] [ARDOPprotocol.ProcessRcvdARQFrame] IDLE received in ProtocolState IRS, substate: IRSData
02:49:01.120 [2.0.4] [Main.SendFrame] Send DataACK delayed 100 ms
02:49:01.222 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=IRS blnFramePending=True next Play in 2 ms
02:49:01.222 [2.0.4] Command Trace TO Host: PTT TRUE
02:49:01.223 [2.0.4] [Main.KeyPTT] True
02:49:01.224 [2.0.4] [PlaySoundStream] DataACK
02:49:01.224 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:49:01.643 [2.0.4] [MainPoll] Play stop. Length = 419 ms
02:49:01.681 [2.0.4] Command Trace TO Host: PTT FALSE
02:49:01.681 [2.0.4] [Main.KeyPTT] False
02:49:01.681 [2.0.4] GetNextARQFrame intPingRpt=0
02:49:02.247 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:02.407 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=30.7dB, Offset=0.00Hz
02:49:05.729 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:49:05.730 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:49:05.730 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:49:05.730 [2.0.4] [ARDOPprotocol.ProcessRcvdARQFrame] Add ARQ Tag to data and send to Host
02:49:05.731 [2.0.4] [AddTagToDataAndSendToHost] Tag:ARQ +bytes=8
02:49:05.731 [2.0.4] Command Trace from HOST: Data (length = 11)
02:49:05.758 [2.0.4] ToolStripLatency.Text = 36 bytes/min
02:49:06.175 [2.0.4] Command Trace from HOST: 13 bytes received by objTCPIPData
02:49:06.175 [2.0.4] Command Trace TO Host: BUFFER 11
02:49:06.861 [2.0.4] Command Trace from HOST: 35 bytes received by objTCPIPData
02:49:06.861 [2.0.4] Command Trace TO Host: BUFFER 44
02:49:07.516 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:07.550 [2.0.4] Command Trace from HOST: 35 bytes received by objTCPIPData
02:49:07.550 [2.0.4] Command Trace TO Host: BUFFER 77
02:49:07.707 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=34.8dB, Offset=0.00Hz
02:49:08.238 [2.0.4] Command Trace from HOST: 35 bytes received by objTCPIPData
02:49:08.238 [2.0.4] Command Trace TO Host: BUFFER 110
02:49:08.987 [2.0.4] Command Trace from HOST: 35 bytes received by objTCPIPData
02:49:08.987 [2.0.4] Command Trace TO Host: BUFFER 143
02:49:09.674 [2.0.4] Command Trace from HOST: 35 bytes received by objTCPIPData
02:49:09.674 [2.0.4] Command Trace TO Host: BUFFER 176
02:49:10.364 [2.0.4] Command Trace from HOST: 35 bytes received by objTCPIPData
02:49:10.364 [2.0.4] Command Trace TO Host: BUFFER 209
02:49:10.939 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:49:10.941 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:49:10.941 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:49:11.050 [2.0.4] Command Trace from HOST: 35 bytes received by objTCPIPData
02:49:11.050 [2.0.4] Command Trace TO Host: BUFFER 242
02:49:11.799 [2.0.4] Command Trace from HOST: 6 bytes received by objTCPIPData
02:49:11.799 [2.0.4] Command Trace TO Host: BUFFER 246
02:49:12.826 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:12.977 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=31.8dB, Offset=0.00Hz
02:49:16.248 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:49:16.250 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:49:16.250 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:49:18.037 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:18.195 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=32.1dB, Offset=0.00Hz
02:49:21.518 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:49:21.520 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:49:21.520 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:49:23.306 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:23.497 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=32.5dB, Offset=0.00Hz
02:49:26.828 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:49:26.830 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:49:26.831 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:49:28.616 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:28.767 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=28.6dB, Offset=0.00Hz
02:49:32.096 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:49:32.097 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:49:32.097 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:49:33.886 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:34.077 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=33.4dB, Offset=0.00Hz
02:49:37.309 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:49:37.310 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:49:37.310 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:49:39.095 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:39.287 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=27.8dB, Offset=0.00Hz
02:49:42.618 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:49:42.620 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:49:42.620 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:49:44.406 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:44.566 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=27.9dB, Offset=0.00Hz
02:49:47.829 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:49:47.830 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:49:47.830 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:49:49.676 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:49.867 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=34.3dB, Offset=0.00Hz
02:49:53.097 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:49:53.099 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:49:53.099 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:49:54.976 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:49:55.137 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=34.9dB, Offset=0.00Hz
02:49:58.409 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:49:58.410 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:49:58.410 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:50:00.276 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:50:00.436 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=29.6dB, Offset=0.00Hz
02:50:03.679 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:50:03.680 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:50:03.681 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:50:05.546 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:50:05.737 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=27.5dB, Offset=0.00Hz
02:50:08.979 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:50:08.980 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:50:08.980 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:50:10.856 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:50:11.017 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=27.6dB, Offset=0.00Hz
02:50:14.349 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:50:14.350 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:50:14.350 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:50:16.126 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:50:16.317 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=28.8dB, Offset=0.00Hz
02:50:19.549 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:50:19.550 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:50:19.550 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:50:21.336 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:50:21.527 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=27.8dB, Offset=0.00Hz
02:50:24.859 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:50:24.860 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:50:24.860 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:50:26.646 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:50:26.807 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=31.1dB, Offset=0.00Hz
02:50:30.038 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:50:30.040 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:50:30.040 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:50:31.826 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:50:32.017 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=29.2dB, Offset=0.00Hz
02:50:35.338 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:50:35.340 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:50:35.340 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:50:37.136 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:50:37.287 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=34.9dB, Offset=0.00Hz
02:50:40.548 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:50:40.550 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:50:40.550 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:50:42.346 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:50:42.497 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=31.8dB, Offset=0.00Hz
02:50:45.828 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:50:45.830 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:50:45.830 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:50:47.616 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:50:47.807 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=28.3dB, Offset=0.00Hz
02:50:51.129 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:50:51.130 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:50:51.131 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:50:52.925 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:50:53.075 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=28.4dB, Offset=0.00Hz
02:50:56.338 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:50:56.340 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:50:56.340 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:50:58.196 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:50:58.387 [2.0.4] [Frame Type OK]9A 16QAM.200.100.O, D1=.00, D2=.00 Ldr; S:N(3KHz) Avg=30.2dB, Offset=0.00Hz
02:51:01.618 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=0 AccOffsetCnt=326/326
02:51:01.620 [2.0.4] [Decode16QAMData] 16QAM.200.100.O 100% decoded
02:51:01.620 [2.0.4] [DecodeFrame] Frame: 16QAM.200.100.O PASS, Quality= 98 bytes= 8
02:51:02.396 [2.0.4] [AcquireFrameSyncRSBAvg] Phase1>2Avg=3.14 Phase2>3=.00
02:51:02.547 [2.0.4] [Frame Type OK]11 16QAM.500.100.E, D2=.00 Ldr; S:N(3KHz) Avg=30.5dB, Offset=0.00Hz
02:51:05.753 [2.0.4] [ARDOPprotocol.PollARQTimeout] Timeout setting SendTimeout timer to start.
02:51:05.861 [2.0.4] ARDOPprotocol.tmrSendTimeout] ARQ Timeout from ProtocolState: IRS Going to DISC state
02:51:05.868 [2.0.4] [Main.SendFrame] Send IDFrame_KA8RYU [DM65] delayed 100 ms
02:51:05.878 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffset=12 AccOffsetCnt=302/326
02:51:05.908 [2.0.4] [CorrectPhaseForTuningOffset] 16QAM AvgOffsetBeginning=11 AvgOffsetEnd=3 AccOffsetCnt=309/326
02:51:05.911 [2.0.4] [Decode16QAMData] 16QAM.500.100.E 0% decoded
02:51:05.911 [2.0.4] [DecodeFrame] Frame: 16QAM.500.100.E FAIL, Quality= 68
02:51:05.911 [2.0.4] [ARDOPprotocol.ProcessNewSamples] blnTimeoutTriggered blocks ProcessRcvdARQFrame
02:51:05.988 [2.0.4] [Main.MainPoll4] objProtocol.Repeating=True ProtocolState=IRS blnFramePending=True next Play in 20 ms
02:51:05.988 [2.0.4] Command Trace TO Host: PTT TRUE
02:51:05.988 [2.0.4] [Main.KeyPTT] True
02:51:05.989 [2.0.4] [PlaySoundStream] IDFrame_KA8RYU [DM65]
02:51:05.989 [2.0.4] [Main.PlaySoundStream] set blnSoundStreamPlay to True
02:51:06.065 [2.0.4] Command Trace TO Host: DISCONNECTED
Server station exception log
====================
02:49:05.731 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:49:10.942 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:49:16.251 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:49:21.521 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:49:26.831 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:49:32.097 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:49:37.311 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:49:42.621 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:49:47.831 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:49:53.099 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:49:58.411 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:50:03.681 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:50:08.981 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:50:14.351 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:50:19.551 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:50:24.861 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:50:30.041 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:50:35.341 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:50:40.551 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:50:45.831 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:50:51.131 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:50:56.341 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)
02:51:01.621 [2.0.4] [ProcessRcvdARQFrame] Trace = 202 Exception: System.IndexOutOfRangeException: Index was outside the bounds of the array.
at ARDOP_Win.ARDOPprotocol.ProcessRcvdARQFrame(Int32 intFrameType, Byte[] bytData, Boolean blnFrameDecodedOK)