JSON output - duplicated data and bad format

[acarslogger]

Hi Thierry,

I've found some JSON format error / duplicated acars output in the JSON output. There are 2 examples below. I've included them in this 1 Github issue as I suspect that are all closely linked to one area of the source code.

The examples include the default log file output and the equivalent JSON output.

Example 1

BA018F (Msg No M33A) sent an FST01 message. There were then 2 acars messages without an actual acars message. Then BA13GV (Msg. no: D00A) sent a long H1 acars message.

[#4 (F:136.875 P:1.8) 14/02/2018 15:14:47.266 --------------------------------
Command from Aircraft:400D89 (airborne) to GroundD:262243 
Frame-I: Ns:2 Nr:1
ACARS
Aircraft reg: G-MEDL Flight id: BA018F
Mode: 2 Msg. label: 15
Block id: 9 Ack: !
Msg. no: M33A
Message :
FST01EGLLEGPDN052435W0007268236  94  16- 3C 61273      388  16071514

[#5 (F:136.975 P:-2.4) 14/02/2018 15:14:47.282 --------------------------------
Command from Aircraft:3C5EF4 (airborne) to GroundD:10983A 
Frame-I: Ns:5 Nr:5

[#5 (F:136.975 P:-2.1) 14/02/2018 15:14:47.788 --------------------------------
Command from Aircraft:461F30 (airborne) to GroundD:214AB7 
Frame-I: Ns:6 Nr:7

[#5 (F:136.975 P:-4.7) 14/02/2018 15:14:48.314 --------------------------------
Response from Aircraft:406230 (airborne) to GroundD:260F37 
Frame-U: DM

[#4 (F:136.875 P:1.9) 14/02/2018 15:14:48.577 --------------------------------
Response from Aircraft:400D89 (airborne) to GroundD:262243 
Frame-S: Nr:2 RR

[#5 (F:136.975 P:-2.0) 14/02/2018 15:14:49.101 --------------------------------
Response from Aircraft:461F30 (airborne) to GroundD:214AB7 
Frame-S: Nr:0 RR

[#5 (F:136.975 P:-0.4) 14/02/2018 15:14:50.165 --------------------------------
Command from Aircraft:4074B0 (airborne) to GroundD:10902A 
Frame-I: Ns:0 Nr:3
ACARS
Aircraft reg: G-EZRR Flight id: U289DM
Mode: 2 Msg. label: _d
Block id: 4 Ack: O
Msg. no: S87A
Message :

[#2 (F:136.775 P:-3.6) 14/02/2018 15:14:50.819 --------------------------------
Response from Aircraft:4BAA6B (airborne) to GroundD:275D25 
Frame-S: Nr:2 RR

[#5 (F:136.975 P:-4.2) 14/02/2018 15:14:50.836 --------------------------------
Response from Aircraft:3C5EF5 (airborne) to GroundD:10914A 
Frame-S: Nr:5 SREJ

[#5 (F:136.975 P:-2.2) 14/02/2018 15:14:50.885 --------------------------------
Response from Aircraft:3C5EF4 (airborne) to GroundD:10983A 
Frame-S: Nr:6 RR

[#5 (F:136.975 P:-2.2) 14/02/2018 15:14:51.065 --------------------------------
Command from Aircraft:3991E9 (airborne) to GroundD:10919A 
Frame-I: Ns:6 Nr:7
ACARS
Aircraft reg: F-HEPJ Flight id: AF1069
Mode: 2 Msg. label: _d
Block id: 7 Ack: B
Msg. no: S46A
Message :

[#4 (F:136.875 P:-3.8) 14/02/2018 15:14:51.625 --------------------------------
Command from Aircraft:406B5B (airborne) to GroundD:261EE1 
Frame-I: Ns:6 Nr:5
ACARS
Aircraft reg: G-GATL Flight id: BA13GV
Mode: 2 Msg. label: H1
Block id: 1 Ack: !
Msg. no: D00A
Message :
#DFBA04/A32004,1,4/CCG-GATL,FEB14,151421,EGKK,LSGG,0000/
C105,18500,4000,03,0100,0,0110,03,X/
CE0067,00701,158,242,6259,303,I20A10/
EC011288,44532,25676,23/
EE017312,08989,04610,23/
N101,13,01,04,07,47,52,65,4795,4800/
N201,13,01,04,08,45,54,64,4620,4630/
S11305,4790,0813,0886,3594,1426,1305/
S21305,4615,0814,0882,3472,1427,1307/
T13465,4665,032,14914,0071,20003/
T23543,4620,025,14906,0071,19921/
V103D01,00404,08000,239,084,0003,1,1/
V203D01,00404,08000,245,084,0005,1,1/
V3011,002,182,XXX,0349,0/
V4002,002,296,XXX,0350,0/

The equivalent JSON output shows

{"timestamp":1518621287.27252,"station_id":"Pi3","channel":3,"freq":136.875,"icao":4197769,"mode":"2","label":"15","block_id":"9","ack":"!","tail":"G-MEDL","flight":"BA018F","msgno":"M33A","text":"FST01EGLLEGPDN052435W0007268236  94  16- 3C 61273      388  16071514","depa":"EGLL","dsta":"EGPD"}
{"timestamp":1518621290.1720109,"station_id":"Pi3","channel":4,"freq":136.975,"icao":4224176,"mode":"2","label":"_d","block_id":"4","ack":"O","tail":"G-EZRR","flight":"U289DM","msgno":"S87A"}
{"timestamp":1518621291.0586081,"station_id":"Pi3","channel":4,"freq":136.975,"icao":3772905,"mode":"2","label":"_d","block_id":"7","ack":"B","tail":"F-HEPJ","flight":"AF1069","msgno":"S46A"}
{"timestamp":1518621291.615262,"station_id":"Pi3","channel":3,"freq":136.875,"icao":4221787,"mode":"2","label":"H1","block_id":"1","ack":"!","tail":"G-GATL","flight":"BA13GV","msgno":"D00A","text":FST01EGLLEGPDN052435W0007268236  94  16- 3C 61273      388  16071514","depa":"EGLL","dsta":"EGPD"}

The long BA13GV H1 message has been replaced with the original BA018F FST message and the json format has been corrupted to show "text":FST01EGLL . It's missing the " at the start of the FST message.

Example 2

AC0855 (Msg No D74M) sent a message starting with #DFB37 13 12 12 131334 There were then 2 acars messages without an actual acars message. Then W609AY (Msg. no: D02A) sent a H1 acars message with #DFBA321,007163,1,1,TB0.

[#1 (F:136.725 P:-0.2) 14/02/2018 14:49:11.506 --------------------------------
Command from Aircraft:C023BD (airborne) to GroundD:11983A 
Frame-I: Ns:5 Nr:4
ACARS
Aircraft reg: C-FNNW Flight id: AC0855
Mode: 2 Msg. label: H1
Block id: 6 Ack: !
Msg. no: D74M
Message :
#DFB37 13 12 12 131334
002211  0  01001000045474532 13 12 12 131332
002211  0  01001000045314529 13 12 12 131331

[#5 (F:136.975 P:-2.3) 14/02/2018 14:49:11.571 --------------------------------
Response from Aircraft:4408D7 (airborne) to GroundD:10983A 
Frame-S: Nr:7 RR

[#5 (F:136.975 P:-1.1) 14/02/2018 14:49:11.833 --------------------------------
Command from GroundD:260F37 (on ground) to Aircraft:406099 
Frame-I: Ns:0 Nr:1

[#4 (F:136.875 P:-2.6) 14/02/2018 14:49:12.359 --------------------------------
Response from Aircraft:461F65 (airborne) to GroundD:262242 
Frame-S: Nr:4 RR

[#5 (F:136.975 P:-1.7) 14/02/2018 14:49:13.111 --------------------------------
Command from Aircraft:A4E822 (airborne) to GroundD:10983A 
Frame-I: Ns:3 Nr:3
ACARS
Aircraft reg: N415QS Flight id: GS415Q
Mode: 2 Msg. label: _d
Block id: 2 Ack: K
Msg. no: M60A
Message :

[#1 (F:136.725 P:-0.1) 14/02/2018 14:49:13.653 --------------------------------
Response from Aircraft:C023BD (airborne) to GroundD:11983A 
Frame-S: Nr:5 RR

[#5 (F:136.975 P:-0.5) 14/02/2018 14:49:13.995 --------------------------------
Command from Aircraft:40612C (airborne) to GroundD:10987A 
Frame-I: Ns:3 Nr:3

[#1 (F:136.725 P:-2.3) 14/02/2018 14:49:14.800 --------------------------------
Command from Aircraft:4400B9 (airborne) to GroundD:11909A 
Frame-I: Ns:3 Nr:5

[#5 (F:136.975 P:-0.9) 14/02/2018 14:49:14.864 --------------------------------
Command from Aircraft:4B18F4 (airborne) to GroundD:10983A 
Frame-I: Ns:7 Nr:3

[#5 (F:136.975 P:-1.1) 14/02/2018 14:49:14.962 --------------------------------
Command from GroundD:29D1D7 (on ground) to Aircraft:4401DC 
Frame-I: Ns:7 Nr:2

[#5 (F:136.975 P:-1.3) 14/02/2018 14:49:15.077 --------------------------------
Command from GroundD:29D1D7 (on ground) to Aircraft:FFFFFF 
Frame-U: XID
Specific options: VDA:ESN:IHN:BHN:BCN
Airport coverage : EGSS 
ATN router nets : ADM: 534954 ARS : 000001
Station system mask : 200000
Station Position 51.9   0.3

[#1 (F:136.725 P:0.9) 14/02/2018 14:49:15.094 --------------------------------
Command from Aircraft:40600F (airborne) to GroundD:1191EA 
Frame-I: Ns:0 Nr:0
ACARS
Aircraft reg: G-EZTE Flight id: U214MX
Mode: 2 Msg. label: Q0
Block id: 1 Ack: !
Msg. no: S78A
Message :

[#1 (F:136.725 P:-2.1) 14/02/2018 14:49:15.177 --------------------------------
Command from Aircraft:3C65C4 (airborne) to GroundD:11983A 
Frame-I: Ns:5 Nr:1

[#5 (F:136.975 P:-1.5) 14/02/2018 14:49:15.651 --------------------------------
Command from Aircraft:471F73 (airborne) to GroundD:2651D7 
Frame-I: Ns:3 Nr:4
ACARS
Aircraft reg: HA-LXR Flight id: W609AY
Mode: 2 Msg. label: H1
Block id: 2 Ack: !
Msg. no: D02A
Message :
#DFBA321,007163,1,1,TB000000/REP048,00,00,1/HA-LXR,14FEB18,144905,EGGW,EPKT,W60009/TIA05WIZ090501,01,  5.00,  6.25/HA14133718,134309,14134341,134638/HB14143142,143320,14143454,14144846,1/AA134139,0,134703,0/AB141007,0,144117,0/AC000000,0,000000,0/AD000000,0,000000,0/KA134143,0,134700,0/KB141015,0,144117,0/KC000000,0,000000,0/KD000000,0,000000,0/BA141020,144018,  8.38,  4.75/BB000000,000000,  0.00,  0.00/BC000000,000000,  0.00,  0.00/BD000000,000000,  0.00,  0.00/CA134653,0,142718,0/CB000000,0,000000,0/CC000000,0,000000,0/CD000000,0,000000,0/DA134700,0,141015,0/DB000000,0,000000,0/DC000000,0,000000,0/DD000000,0,000000,0/EA000/EB000/EC000/ED035/EE035/EF029/EG023/EH040/FA01146,03157/FB01146,03159/FC07099/GA0139/MA  527/NA  51.8804, 0.000168/PA-  0.3746, 0.000092/QA035,000/RA 19.75, 19.00, 19.50, 18.75/SA1433,1469/TA135018,0,141153/UA135022,0,141146,  8440/:

The equivalent JSON output shows

{"timestamp":1518619751.496139,"station_id":"Pi3","channel":0,"freq":136.725,"icao":12592061,"mode":"2","label":"H1","block_id":"6","ack":"!","tail":"C-FNNW","flight":"AC0855","msgno":"D74M","text":"#DFB37 13 12 12 131334\r\n002211  0  01001000045474532 13 12 12 131332\r\n002211  0  01001000045314529 13 12 12 131331"}
{"timestamp":1518619753.1174209,"station_id":"Pi3","channel":4,"freq":136.975,"icao":10807330,"mode":"2","label":"_d","block_id":"2","ack":"K","tail":"N415QS","flight":"GS415Q","msgno":"M60A"}
{"timestamp":1518619755.657136,"station_id":"Pi3","channel":4,"freq":136.975,"icao":4661107,"mode":"2","label":"H1","block_id":"2","ack":"!","tail":"HA-LXR","flight":"W609AY","msgno":"D02A","text"::"#DFB37 13 12 12 131334\r\n002211  0  01001000045474532 13 12 12 131332\r\n002211  0  01001000045314529 13 12 12 131331"}

The W609AY H1 message has been replaced with the original AC0855 '#DFB37 13 12 12 1313...' message and the json format has been corrupted to show "text"::"#DFB37 13 12 1 . It's now got 2 colons after the text token.

I can supply more examples if required. I haven't checked yet if this also applies to acarsdec. Regards Stuart

[TLeconte]

really strange. It's could only be a problem with the cJSON lib or a bad use of the lib by vdlm2dec, because it outputs a just plain bad json Alas, its contributed code that I did not write, so I have to try to understand how the json lib works ...

Edit : Ok I have a clue. In fact, in the second bad message, the json is correctly outputted until the text output, then something brokes in cJSON lib and it don't write in the ouput buffer and don't even terminate it by a \0 , so you got what is remaining in the out buffer, which could be the previous long message. In your example 2 , 'text' in the second message comes one char earlier than in the first message, so you got these double ::

[TLeconte]

could you check commit 66e376fecc6c316ce8da45893c30a7370abb14c1

[acarslogger]

I have the new version up and running. Looks OK at the moment, but need to wait until I have a larger log file to analyse properly. Stuart

[acarslogger]

Hi Thierry. I've looked through the logs from the last 24 hours and everything looks good. I couldn't find any duplicates or corrupt data. Thanks

[TLeconte]

Great. By the way acarsdec had the same problem Thanks fot testing