https://github.com/osquery/osquery logo
Join Slack
Powered by
Anyone experienced querying the unified_log table?...
# macos
f
Anyone experienced querying the unified_log table? my results are super unpredicatable. I read some of the table definition and it mentions the timestamp and automatic pagination could cause issues, but my primary issue is, I cannot get osquery to return debug logs, when I know for a fact they are present. I can run a CLI log command and pull out the messages I am going for. Ideas?
Copy code
osquery> select DISTINCT level from unified_log where timestamp > -1 and timestamp > (select unix_time - 86400 from time) AND level != 'default';
+-------+
| level |
+-------+
|       |
| error |
+-------+
maybe my window is too small? or i am doing the bounding wrong? thanks
b
Potentially the default for max_rows is too small / filtering too early in the process (it's kind of unclear and hard to predict when max_rows gets applied in the order of filters) Some other discussion/tips https://osquery.slack.com/archives/C08VA8R6F/p1698866074601939?thread_ts=1698245245.206439&cid=C08VA8R6F
g
We have never had good results with the built in table, which is why https://github.com/macadmins/osquery-extension/blob/main/tables/unifiedlog/unified_log.go continues to exist
💯 1
👍 1
f
thanks @grahamgilbert I will check it out.
@Brad Girardeau I can refer to the docs if need be but offhand, is maxrows akin to sql limit in that it will return 1000 rows, or is it internal to the logic of the 
log
command and limits how many logs will be sent to the predicate filter? Thank you.
b
It is internal to the logic of osquery's implementation of the table (which is closely related to but a distinct codebase from what 
log
does)
f
gotcha, yeah for whatever reason, i cannot get the osquery unified_log table to ever return a "debug" log
b
Yeah it's tricky this illustrates some of the differences in querying, and I think there may actually be a bug (see below). Using "predicate" column is closest to running 
log
directly (similar to MacAdmins extension), where the predicate is applied before the max_rows filtering:
Copy code
select * from unified_log where predicate = 'logType = "debug"' and timestamp > (select unix_time - 60 from time) and max_rows = 100 limit 10;
Bumping max_rows to a much higher limit shows the debug logs are there, but are getting filtered out too early by max_rows instead of doing the 
level
column filter early:
Copy code
select * from unified_log where level = 'debug' and timestamp > (select unix_time - 60 from time) and max_rows = 10000 limit 10;
Copy code
select * from unified_log where level = 'debug' and timestamp > (select unix_time - 60 from time) and max_rows = 100 limit 10;
If you run with 
osqueryi --planner
you'll see the reason for this behavior is that 
level
constraint is not passed to the 
unified_log
table implementation, so it's done as a post query filter in the SQL engine instead. It looks like this is actually a bug, and 
level
should get passed into the table by setting 
additional=True
in the schema here.
f
oh interesting
Copy code
osquery> select message, predicate, subsystem, process from unified_log where timestamp > -1 and max_rows = 1000 AND level = 'debug';
osquery planner: xBestIndex Evaluating constraints for table: unified_log [index=0 column=0 term=0 usable=1]
osquery planner: xBestIndex Adding index constraint for table: unified_log [column=timestamp arg_index=1 op=4]
osquery planner: xBestIndex Evaluating constraints for table: unified_log [index=1 column=11 term=1 usable=1]
osquery planner: xBestIndex Adding index constraint for table: unified_log [column=max_rows arg_index=2 op=2]
osquery planner: xBestIndex Evaluating constraints for table: unified_log [index=2 column=10 term=2 usable=1]
osquery planner: xBestIndex Recording constraint set for table: unified_log [cost=1.000000 size=2 idx=37]
osquery planner: xOpen Opening cursor (35) for table: unified_log
osquery planner: xFilter Filtering called for table: unified_log [constraint_count=1 argc=2 idx=37]
osquery planner: xFilter Adding constraint to cursor (35): timestamp > -1
osquery planner: xFilter Adding constraint to cursor (35): max_rows = 1000
osquery planner: Scanning rows for cursor (35)
osquery planner: xFilter unified_log generate returned row count:1000
osquery planner: Closing cursor (35)
@Kathy Satterlee You helped me with a bug previously, should I create a report for this?
5 Views
Open in Slack
PreviousNext
Powered by