V1.0.3 Seeing a Get error when collecting events

[Esky73]

Hi Seeing the following when adding my 1st input to LA - couldn't see this message in other posts

127.0.0.1 - splunk-system-user [14/Nov/2018:16:33:39.805 +1100] "GET /servicesNS/nobody/TA-ms-loganalytics/TA_ms_loganalytics_log_analytics?--cred--=1&output_mode=json&count=0 HTTP/1.1" 200 2096 - - - 927ms
127.0.0.1 - splunk-system-user [14/Nov/2018:16:33:40.613 +1100] "GET /servicesNS/nobody/TA-ms-loganalytics/data/inputs/log_analytics?count=0&output_mode=json HTTP/1.1" 200 2300 - - - 38ms
127.0.0.1 - splunk-system-user [14/Nov/2018:16:33:40.656 +1100] "GET /servicesNS/nobody/TA-ms-loganalytics/storage/passwords/?count=-1&offset=0 HTTP/1.1" 200 233366 - - - 8ms
127.0.0.1 - splunk-system-user [14/Nov/2018:16:33:40.738 +1100] "GET /servicesNS/nobody/TA-ms-loganalytics/TA_ms_loganalytics_settings/logging?--cred--=1&output_mode=json&count=0 HTTP/1.1" 200 1239 - - - 1526ms
127.0.0.1 - splunk-system-user [14/Nov/2018:16:33:41.798 +1100] "GET /servicesNS/nobody/TA-ms-loganalytics/properties/TA-ms-loganalytics HTTP/1.1" 404 151 - - - 0ms
127.0.0.1 - splunk-system-user [14/Nov/2018:16:33:41.804 +1100] "GET /servicesNS/nobody/TA-ms-loganalytics/configs/conf-ta_ms_loganalytics_settings/_reload HTTP/1.1" 200 2106 - - - 23ms
127.0.0.1 - splunk-system-user [14/Nov/2018:16:33:41.830 +1100] "GET /servicesNS/nobody/TA-ms-loganalytics/configs/conf-ta_ms_loganalytics_settings/logging?output_mode=json HTTP/1.1" 200 1713 - - - 1ms
127.0.0.1 - splunk-system-user [14/Nov/2018:16:33:42.270 +1100] "GET /servicesNS/nobody/TA-ms-loganalytics/storage/collections/config/TA_ms_loganalytics_checkpointer HTTP/1.1" 200 5631 - - - 1ms
127.0.0.1 - splunk-system-user [14/Nov/2018:16:33:42.272 +1100] "GET /servicesNS/nobody/TA-ms-loganalytics/storage/collections/config/?search=TA_ms_loganalytics_checkpointer&count=-1&offset=0 HTTP/1.1" 200 4829 - - - 1ms
127.0.0.1 - splunk-system-user [14/Nov/2018:16:33:42.277 +1100] "GET /servicesNS/nobody/TA-ms-loganalytics/storage/collections/data/TA_ms_loganalytics_checkpointer/soc_diagnostics_rg_01 HTTP/1.1" 404 140 - - - 1ms
2018-11-14 16:33:44,747 ERROR pid=74474 tid=MainThread file=base_modinput.py:log_error:307 | Get error when collecting events.
Traceback (most recent call last):
  File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/ta_ms_loganalytics/modinput_wrapper/base_modinput.py", line 127, in stream_events
    self.collect_events(ew)
  File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py", line 96, in collect_events
    input_module.collect_events(self, ew)
  File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/input_module_log_analytics.py", line 86, in collect_events
    for i in range(len(data["tables"][0]["rows"])):
UnboundLocalError: local variable 'data' referenced before assignment
Collapse
11-14-2018 16:33:44.747 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py" Traceback (most recent call last):
11-14-2018 16:33:44.747 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py"   File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/ta_ms_loganalytics/modinput_wrapper/base_modinput.py", line 127, in stream_events
11-14-2018 16:33:44.747 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py"     self.collect_events(ew)
11-14-2018 16:33:44.747 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py"   File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py", line 96, in collect_events
11-14-2018 16:33:44.747 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py"     input_module.collect_events(self, ew)
11-14-2018 16:33:44.747 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py"   File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/input_module_log_analytics.py", line 86, in collect_events
11-14-2018 16:33:44.747 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py"     for i in range(len(data["tables"][0]["rows"])):
11-14-2018 16:33:44.747 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py" UnboundLocalError: local variable 'data' referenced before assignment

[jkat54]

Try using this article to convert the query to the “legacy”
Style that the api version this app uses will support.

https://docs.microsoft.com/en-us/azure/log-analytics/log-analytics-log-search-transition

I think this will work

Type=SecurityBaseline AnalyzeResult=Failed

[jkat54]

Apparently that link has been updated... doesn’t have the legacy to new conversion table it used to have...

This is the best I can find now:
https://gallery.technet.microsoft.com/OMS-Cookbook-The-Lost-dadb9e3d

[jkat54]

Looks like your kvstore is failing. You’re gettting a 404 not found error on the collections endpoint.

Do you have any errors in mongod.log?

index=_internal sourcetype=mongod

[jaxjohnny2000]

no errors for me on this search

[jkat54]

Please create your own question and reference this one if you need to.

[Esky73]

hiya - no i don;t have any errors shown in mongod

[jkat54]

What happens if you do this:

curl -k https://localhost:8089/servicesNS/nobody/TA-ms-loganalytics/storage/collections/data/TA_ms_loganalyt...

From the splunk server that the input is configured on?

[Esky73]

running on the HF with the app on as the splunk user

<msg type="ERROR">Unauthorized</msg>

[jkat54]

Add -u admin to the curl command and when prompted give it your admin password.

[Esky73]

<msg type="ERROR">Could not find object.</msg>

[jkat54]

Your kvstore is broken.

Please fix your kvstore.

[jkat54]

127.0.0.1 - splunk-system-user [14/Nov/2018:16:33:42.277 +1100] "GET /servicesNS/nobody/TA-ms-loganalytics/storage/collections/data/TA_ms_loganalytics_checkpointer/soc_diagnostics_rg_01 HTTP/1.1" 404 140 - - - 1ms

This error is message is saying your kvstore endpoint isn’t being found. The app uses these endpoints to create/check deltas.

[Esky73]

/opt/splunk/bin/splunk show kvstore-status

This member:
backupRestoreStatus : Ready
date : Thu Nov 22 23:41:23 2018
dateSec : 1542890483.041
disabled : 0
guid : 5BCF0670-68E5-450C-BAD6-03C3F24D8E7E
oplogEndTimestamp : Thu Nov 22 23:41:18 2018
oplogEndTimestampSec : 1542890478
oplogStartTimestamp : Fri Feb 9 23:55:28 2018
oplogStartTimestampSec : 1518180928
port : 8191
replicaSet : 5BCF0670-68E5-450C-BAD6-03C3F24D8E7E
replicationStatus : KV store captain
standalone : 1
status : ready

KV store members:
127.0.0.1:8191
configVersion : 1
electionDate : Thu Nov 22 23:29:37 2018
electionDateSec : 1542889777
hostAndPort : 127.0.0.1:8191
optimeDate : Thu Nov 22 23:41:18 2018
optimeDateSec : 1542890478
replicationStatus : KV store captain
uptime : 708

[Esky73]

curl -k -u admin:XXXXXX https://localhost:8089/services/kvstore/status

  https://localhost:8089/services/kvstore/status
  2018-11-22T23:46:05+11:00

    <name>Splunk</name>


  1
  30
  0


    <title>status</title>
    <id>https://localhost:8089/services/kvstore/status/status</id>
    <updated>1970-01-01T10:00:00+10:00</updated>
    <link href="/services/kvstore/status/status" rel="alternate"/>
    <author>
      <name>system</name>
    </author>
    <link href="/services/kvstore/status/status" rel="list"/>
    <content type="text/xml">
      <s:dict>
        <s:key name="current">
          <s:dict>
            <s:key name="backupRestoreStatus">Ready</s:key>
            <s:key name="date">Thu Nov 22 23:46:05 2018</s:key>
            <s:key name="dateSec">1542890765.063</s:key>
            <s:key name="disabled">0</s:key>
            <s:key name="guid">5BCF0670-68E5-450C-BAD6-03C3F24D8E7E</s:key>
            <s:key name="oplogEndTimestamp">Thu Nov 22 23:45:59 2018</s:key>
            <s:key name="oplogEndTimestampSec">1542890759</s:key>
            <s:key name="oplogStartTimestamp">Fri Feb  9 23:55:28 2018</s:key>
            <s:key name="oplogStartTimestampSec">1518180928</s:key>
            <s:key name="port">8191</s:key>
            <s:key name="replicaSet">5BCF0670-68E5-450C-BAD6-03C3F24D8E7E</s:key>
            <s:key name="replicationStatus">KV store captain</s:key>
            <s:key name="standalone">1</s:key>
            <s:key name="status">ready</s:key>
          </s:dict>
        </s:key>
        <s:key name="eai:acl">
          <s:dict>
            <s:key name="app"></s:key>
            <s:key name="can_list">1</s:key>
            <s:key name="can_write">1</s:key>
            <s:key name="modifiable">0</s:key>
            <s:key name="owner">system</s:key>
            <s:key name="perms">
              <s:dict>
                <s:key name="read">
                  <s:list>
                    <s:item>admin</s:item>
                    <s:item>splunk-system-role</s:item>
                  </s:list>
                </s:key>
                <s:key name="write">
                  <s:list>
                    <s:item>admin</s:item>
                    <s:item>splunk-system-role</s:item>
                  </s:list>
                </s:key>
              </s:dict>
            </s:key>
            <s:key name="removable">0</s:key>
            <s:key name="sharing">system</s:key>
          </s:dict>
        </s:key>
        <s:key name="members">
          <s:dict>
            <s:key name="0">
              <s:dict>
                <s:key name="configVersion">1</s:key>
                <s:key name="electionDate">Thu Nov 22 23:29:37 2018</s:key>
                <s:key name="electionDateSec">1542889777</s:key>
                <s:key name="hostAndPort">127.0.0.1:8191</s:key>
                <s:key name="lastHeartbeat"></s:key>
                <s:key name="lastHeartbeatRecv"></s:key>
                <s:key name="lastHeartbeatRecvSec"></s:key>
                <s:key name="lastHeartbeatSec"></s:key>
                <s:key name="optimeDate">Thu Nov 22 23:45:59 2018</s:key>
                <s:key name="optimeDateSec">1542890759</s:key>
                <s:key name="pingMs"></s:key>
                <s:key name="replicationStatus">KV store captain</s:key>
                <s:key name="uptime">990</s:key>
              </s:dict>
            </s:key>
          </s:dict>
        </s:key>
      </s:dict>
    </content>


root@ESKY:/home/esky#

[Esky73]

OK Found it ...

I was given a search by the azure team :

SecurityEvent
| top 100 by TimeGenerated
| extend localtime = TimeGenerated-8h

in the logs :

2018-11-23 00:04:18,369 INFO pid=10820 tid=MainThread file=connectionpool.py:_new_conn:758 | Starting new HTTPS connection (1): 127.0.0.1
2018-11-23 00:04:21,666 INFO pid=10820 tid=MainThread file=connectionpool.py:_new_conn:758 | Starting new HTTPS connection (1): 127.0.0.1
2018-11-23 00:04:27,203 INFO pid=10820 tid=MainThread file=setup_util.py:log_info:114 | Log level is not set, use default INFO
2018-11-23 00:04:27,204 INFO pid=10820 tid=MainThread file=splunk_rest_client.py:_request_handler:100 | Use HTTP connection pooling
2018-11-23 00:04:27,207 INFO pid=10820 tid=MainThread file=connectionpool.py:_new_conn:758 | Starting new HTTPS connection (1): 127.0.0.1
2018-11-23 00:04:27,245 INFO pid=10820 tid=MainThread file=log.py:info:103 | ae101a0e-9177-493e-bb7d-fd6786cdf5a8 - TokenRequest:Getting token with client credentials.
2018-11-23 00:04:32,869 INFO pid=10820 tid=MainThread file=log.py:info:103 | ae101a0e-9177-493e-bb7d-fd6786cdf5a8 - OAuth2Client:Get Token Server returned this correlation_id: ae101a0e-9177-493e-bb7d-fd6786cdf5a8
2018-11-23 00:04:38,515 ERROR pid=10820 tid=MainThread file=base_modinput.py:log_error:307 | OMSInputName="test" status="400" step="Post Query" response="{"error":{"message":"The request had some invalid properties","code":"BadArgumentError","innererror":{"code":"SemanticError","message":"A semantic error occurred.","innererror":{"code":"SEM0100","message":"'top' operator: Failed to resolve table or column expression named 'SecurityEvent'"}}}}"
2018-11-23 00:04:38,517 ERROR pid=10820 tid=MainThread file=base_modinput.py:log_error:307 | Get error when collecting events.
Traceback (most recent call last):
  File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/ta_ms_loganalytics/modinput_wrapper/base_modinput.py", line 127, in stream_events
    self.collect_events(ew)
  File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py", line 96, in collect_events
    input_module.collect_events(self, ew)
  File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/input_module_log_analytics.py", line 86, in collect_events
    for i in range(len(data["tables"][0]["rows"])):
UnboundLocalError: local variable 'data' referenced before assignment

tested with a different search :

AzureActivity
| summarize count() by Category

It Works!

[Esky73]

OK last update - have tested with several other searches - and all fail when requesting SecurityEvent - eg :

SecurityEvent
| top 10 by TimeGenerated

fails - and

AzureActivity
| top 10 by TimeGenerated

writes to index

[jkat54]

It supports the legacy OMS searches

[Esky73]

Also installed on a standalone instance and seeing the very same issue :

20/11/2018
15:43:44.385    
11-20-2018 15:43:44.385 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py" ERRORlocal variable 'data' referenced before assignment
host =  esky-splunk source =    /opt/splunk/var/log/splunk/splunkd.log sourcetype = splunkd
20/11/2018
15:43:44.065    
11-20-2018 15:43:44.065 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py" UnboundLocalError: local variable 'data' referenced before assignment
host =  esky-splunk source =    /opt/splunk/var/log/splunk/splunkd.log sourcetype = splunkd
20/11/2018
15:43:44.065    
11-20-2018 15:43:44.065 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py"     for i in range(len(data["tables"][0]["rows"])):
host =  esky-splunk source =    /opt/splunk/var/log/splunk/splunkd.log sourcetype = splunkd
20/11/2018
15:43:44.065    
11-20-2018 15:43:44.065 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py"   File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/input_module_log_analytics.py", line 86, in collect_events
host =  esky-splunk source =    /opt/splunk/var/log/splunk/splunkd.log sourcetype = splunkd
20/11/2018
15:43:44.065    
11-20-2018 15:43:44.065 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py"     input_module.collect_events(self, ew)
host =  esky-splunk source =    /opt/splunk/var/log/splunk/splunkd.log sourcetype = splunkd
20/11/2018
15:43:44.065    
11-20-2018 15:43:44.065 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py"   File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py", line 96, in collect_events
host =  esky-splunk source =    /opt/splunk/var/log/splunk/splunkd.log sourcetype = splunkd
20/11/2018
15:43:44.065    
11-20-2018 15:43:44.065 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py"     self.collect_events(ew)
host =  esky-splunk source =    /opt/splunk/var/log/splunk/splunkd.log sourcetype = splunkd
20/11/2018
15:43:44.065    
11-20-2018 15:43:44.065 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py"   File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/ta_ms_loganalytics/modinput_wrapper/base_modinput.py", line 127, in stream_events
host =  esky-splunk source =    /opt/splunk/var/log/splunk/splunkd.log sourcetype = splunkd
20/11/2018
15:43:44.065    
11-20-2018 15:43:44.065 +1100 ERROR ExecProcessor - message from "python /opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py" Traceback (most recent call last):
host =  esky-splunk source =    /opt/splunk/var/log/splunk/splunkd.log sourcetype = splunkd
20/11/2018
15:43:44.064    
2018-11-20 15:43:44,064 ERROR pid=20703 tid=MainThread file=base_modinput.py:log_error:307 | Get error when collecting events.
Traceback (most recent call last):
  File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/ta_ms_loganalytics/modinput_wrapper/base_modinput.py", line 127, in stream_events
    self.collect_events(ew)
  File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/log_analytics.py", line 96, in collect_events
    input_module.collect_events(self, ew)
  File "/opt/splunk/etc/apps/TA-ms-loganalytics/bin/input_module_log_analytics.py", line 86, in collect_events
    for i in range(len(data["tables"][0]["rows"])):
UnboundLocalError: local variable 'data' referenced before assignment
Collapse
host =  esky-splunk source =    /opt/splunk/var/log/splunk/ta_ms_loganalytics_log_analytics.log sourcetype =    ta:ms:loganalytics:log

[jkat54]

Does the standalone server also have this error?

127.0.0.1 - splunk-system-user [14/Nov/2018:16:33:42.277 +1100] "GET /servicesNS/nobody/TA-ms-loganalytics/storage/collections/data/TA_ms_loganalytics_checkpointer/soc_diagnostics_rg_01 HTTP/1.1" 404 140 - - - 1ms

If not, then it’s a different issue.