The OMS agent is generating malformed json file

[johanburati]

The OMS agent is generating malformed json file, which generates WARNING messages in the waagent.log file.

I have collected one of the file and was able to reproduce the issue on another server.

watcher.log:

2019/01/30 13:17:13 [Microsoft.EnterpriseCloud.Monitoring.OmsAgentForLinux-1.8.11] /var/lib/waagent/events/1548850633269799.tld

waagent.log:

2019/01/30 13:18:01.897150 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1

1548850633269799.tld:

# ls -l  1548850633269799.tld
-rw-r--r--. 1 root root 7620 Jan 30 13:17 1548850633269799.tld

# cat 1548850633269799.tld
 {
            "eventId": 1,
            "providerId": "69B669B9-4AF8-4C50-BDC4-6006FA76E975",
            "parameters": [
                        {
                        "name": "Name",
                        "value": "Microsoft.EnterpriseCloud.Monitoring.OmsAgentForLinux"
                },
                        {

            			"name": "Version",
            			"value": "1.8.11"
             		},

                        {
                        "name": "Operation",
                        "value": "DscPerformConsistency"
                },
                        {
                        "name": "OperationSuccess",
                        "value": false
                },
                        {
                        "name": "Message",
                        "value": "/opt/omi/bin/omicli: result: MI_RESULT_FAILED\n/opt/omi/bin/omicli: result: Failed to apply the configuration.  These resources produced errors: [MSFT_nxOMSAutomationWorkerResource]AutoRegister01\n\n---LOG---\n2019/01/30 13:00:35: WARNING: null(0): EventId=2 Priority=WARNING Job A7FC6963-6837-4FC3-BF46-59410045680C : PerformRequiredConfigurationChecks DSC operation completed in 34.4137 seconds.\n2019/01/30 13:15:01: WARNING: null(0): EventId=2 Priority=WARNING Job 821EF6A7-77C4-46A3-8BCA-9C8A6A25F324 : Starting PerformRequiredConfigurationChecks DSC operation.\n2019/01/30 13:15:25: WARNING: null(0): EventId=2 Priority=WARNING Job 821EF6A7-77C4-46A3-8BCA-9C8A6A25F324 : \nDisplaying messages from built-in DSC resources:\n\t WMI channel 1 \n\t ResourceID:  \n\t Message : [ZNLWENDMYSQL52]:                            [] Starting consistency engine.\n2019/01/30 13:15:25: WARNING: null(0): EventId=2 Priority=WARNING Job 821EF6A7-77C4-46A3-8BCA-9C8A6A25F324 : \nDisplaying messages from built-in DSC resources:\n\t WMI channel 1 \n\t ResourceID:  \n\t Message : [ZNLWENDMYSQL52]:                            [] A pending configuration exists. DSC will process a set request on the pending configuration.\n2019/01/30 13:15:26: INFO: Scripts/nxOMSPlugin.pyc(114):\nOMSAgent is multi-homed and resource is updating workspace 217c5ff1-de1d-41f0-870d-5bbdd5e02e74\n2019/01/30 13:15:26: INFO: Scripts/nxOMSSyslog.pyc(56):\nConfig file is /etc/opt/omi/conf/omsconfig/rsyslog-oms.conf.\n2019/01/30 13:15:26: INFO: Scripts/nxOMSSyslog.pyc(189):\nSuccessfully read /etc/rsyslog.d/95-omsagent.conf.\n2019/01/30 13:15:26: INFO: Scripts/nxOMSSyslog.pyc(458):\nSuccesfully read /etc/opt/microsoft/omsagent/217c5ff1-de1d-41f0-870d-5bbdd5e02e74/conf/omsagent.d/syslog.conf for syslog port.\n2019/01/30 13:15:26: INFO: Scripts/nxOMSPerfCounter.pyc(40):\nConfiguration is in a workspace-specific path; resource is updating workspace 217c5ff1-de1d-41f0-870d-5bbdd5e02e74\n2019/01/30 13:15:26: INFO: Scripts/nxOMSPerfCounter.pyc(302):\nRead omsagent configuration /etc/opt/microsoft/omsagent/217c5ff1-de1d-41f0-870d-5bbdd5e02e74/conf/omsagent.conf.\n2019/01/30 13:15:26: INFO: Scripts/nxOMSPerfCounter.pyc(302):\nRead omsagent configuration /etc/opt/microsoft/omsagent/217c5ff1-de1d-41f0-870d-5bbdd5e02e74/conf/omsagent.conf.\n2019/01/30 13:15:26: DEBUG: Scripts/nxOMSAutomationWorker.pyc(762):\nUpdatesEnabled is True; AutomationWorkerEnabled is True\n2019/01/30 13:15:26: INFO: Scripts/nxOMSAutomationWorker.pyc(762):\nnxautomation was found on the system\n2019/01/30 13:15:26: INFO: Scripts/nxOMSAutomationWorker.pyc(762):\nFailed to read nxautomation user processes\n2019/01/30 13:15:26: INFO: Scripts/nxOMSAutomationWorker.pyc(762):\nFailed to read nxautomation user processes\n2019/01/30 13:15:26: INFO: Scripts/nxOMSAutomationWorker.pyc(762):\nFailed to read nxautomation user processes\n2019/01/30 13:15:26: INFO: Scripts/nxOMSAutomationWorker.pyc(762):\nFailed to detect instance of worker manager\n2019/01/30 13:15:26: DEBUG: Scripts/nxOMSAutomationWorker.pyc(762):\nrunning version is: 0.0\n2019/01/30 13:15:26: DEBUG: Scripts/nxOMSAutomationWorker.pyc(762):\nlatest available version is: 1.6.3.0\n2019/01/30 13:15:26: INFO: Scripts/nxOMSAutomationWorker.pyc(762):\nTest_Marshall returned [-1]: worker manager isn't running or is not latest\n2019/01/30 13:15:26: INFO: Scripts/nxOMSAutomationWorker.pyc(762):\nnxautomation was found on the system\n2019/01/30 13:15:26: INFO: Scripts/nxOMSAutomationWorker.pyc(762):\nFailed to read nxautomation user processes\n2019/01/30 13:15:26: DEBUG: Scripts/nxOMSAutomationWorker.pyc(762):\nNo old worker process to terminate\n2019/01/30 13:15:26: DEBUG: Scripts/nxOMSAutomationWorker.pyc(762):\nKilling the instance of worker manager already running\n2019/01/30 13:15:26: DEBUG: Scripts/nxOMSAutomationWorker.pyc(762):\nNo process to terminate\n2019/01/30 13:15:26: INFO: Scripts/nxOMSAutomationWorker.pyc(762):\nFailed to read nxautomation user processes\n2019/01/30 13:15:26: INFO: Scripts/nxOMSAutomationWorker.pyc(762):\nFailed to detect instance of worker manager\n2019/01/30 13:15:26: DEBUG: Scripts/nxOMSAutomationWorker.pyc(762):\nNo worker manager processes to be killed\n2019/01/30 13:15:26: INFO: Scripts/nxOMSAutomationWorker.pyc(762):\nFailed to read nxautomation user processes\n2019/01/30 13:15:26: DEBUG: Scripts/nxOMSAutomationWorker.pyc(762):\noms.conf file was written\n2019/01/30 13:15:29: ERROR: Scripts/nxOMSAutomationWorker.pyc(762):\nSet_Marshall returned [-1] with following error: Traceback (most recent call last):\n  File "Scripts/nxOMSAutomationWorker.py", line 151, in Set_Marshall\n    + stderr + "\n" + stdout)\nException: Linux Hybrid Worker registration failed: Return code 1 :Traceback (most recent call last):\n  File "/opt/microsoft/omsconfig/modules/nxOMSAutomationWorker/DSCResources/MSFT_nxOMSAutomationWorkerResource/automationworker/scripts/register_oms.py", line 447, in <module>\n    main(sys.argv[1:])\n  File "/opt/microsoft/omsconfig/modules/nxOMSAutomationWorker/DSCResources/MSFT_nxOMSAutomationWorkerResource/automationworker/scripts/register_oms.py", line 426, in main\n    azure_resource_id, test_mode, platform_update_domain, tags)\n  File "/opt/microsoft/omsconfig/modules/nxOMSAutomationWorker/DSCResources/MSFT_nxOMSAutomationWorkerResource/automationworker/scripts/register_oms.py", line 202, in register\n    raise Exception("Unable to register [status_code=" + str(response.status_code) + "]")\nException: Unable to register [status_code=400]\n\n\n\n2019/01/30 13:15:29: ERROR: null(0): EventId=1 Priority=ERROR Job 821EF6A7-77C4-46A3-8BCA-9C8A6A25F324 : \nThis event indicates that failure happens when LCM is processing the configuration. ErrorId is 1. ErrorDetail is The SendConfigurationApply function did not succeed.. ResourceId is [MSFT_nxOMSAutomationWorkerResource]AutoRegister01 and SourceInfo is null. ErrorMessage is A general error occurred, not covered by a more specific error code.. The related ResourceID is [MSFT_nxOMSAutomationWorkerResource]AutoRegister01..\n2019/01/30 13:15:30: ERROR: null(0): EventId=1 Priority=ERROR Job 821EF6A7-77C4-46A3-8BCA-9C8A6A25F324 : \nDSC Engine Error : \n\t Error Message Failed to apply the configuration.  These resources produced errors: [MSFT_nxOMSAutomationWorkerResource]AutoRegister01 \n\tError Code : 1 \n2019/01/30 13:15:30: WARNING: null(0): EventId=2 Priority=WARNING Job 821EF6A7-77C4-46A3-8BCA-9C8A6A25F324 : \nDisplaying messages from built-in DSC resources:\n\t WMI channel 1 \n\t ResourceID:  \n\t Message : [ZNLWENDMYSQL52]:                            [] Consistency check completed.\n"
                },
                        {
                        "name": "Duration",
                        "value": 300000
                }
            ]
            }
			
	```

# cat 1548850633269799.tld | python -m json.tool
Expecting , delimiter: line 25 column 4621 (char 5382)

The file is not a properly formatted json file, there is an issue with the value field on line 25.

[johanburati]

This issue is still not fixed in the latest release 1.10.5, the logs are getting filled with those errors:

watcher.log:

2019/06/05 17:51:10 [Microsoft.EnterpriseCloud.Monitoring.OmsAgentForLinux-1.10.5] /var/lib/waagent/events/1559782270596111.tld
2019/06/05 17:53:32 [Microsoft.EnterpriseCloud.Monitoring.OmsAgentForLinux-1.10.5] /var/lib/waagent/events/1559782412564967.tld
2019/06/05 17:57:10 [Microsoft.EnterpriseCloud.Monitoring.OmsAgentForLinux-1.10.5] /var/lib/waagent/events/1559782630826572.tld```

waagent.log:

2019/06/04 13:08:34.760329 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1
2019/06/04 14:17:40.164123 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1
2019/06/04 15:07:44.070814 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1

[johncrim]

I posted a related issue here: #975 - in short, OmsAgent is emitting JSON files, but the WaLinuxAgent source code clearly shows that it expects XML event files in the /var/lib/waagent/events/ dir.

[maccas777]

I am also having issue with this

python: WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1

my waagent log

2019/07/11 15:04:12.077981 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1
2019/07/11 15:09:15.634147 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1
2019/07/11 15:14:19.218500 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1
2019/07/11 15:19:21.706711 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1
2019/07/11 15:24:25.268384 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1
2019/07/11 15:29:26.667209 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1
2019/07/11 15:34:29.337154 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1
2019/07/11 15:39:29.832826 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1
2019/07/11 15:44:32.302389 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1
2019/07/11 15:49:32.795438 WARNING ExtHandler Failed to decode event file: not well-formed (invalid token): line 1, column 1

[hestolz]

Thank you for your submission. As previously announced, the Log Analytics agent has been deprecated and has no support as of August 31, 2024. If you use the Log Analytics agent to ingest data to Azure Monitor, migrate now to the new Azure Monitor agent. As part of repo archival, open issues and pull requests will be closed.