You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@metron.apache.org by "ASF GitHub Bot (JIRA)" <ji...@apache.org> on 2016/10/25 14:25:58 UTC
[jira] [Commented] (METRON-443) Exception seen while running
stellar or fixed query on pcap data
[ https://issues.apache.org/jira/browse/METRON-443?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15605456#comment-15605456 ]
ASF GitHub Bot commented on METRON-443:
---------------------------------------
GitHub user justinleet opened a pull request:
https://github.com/apache/incubator-metron/pull/321
METRON-443 Exception seen while running stellar or fixed query on pcap data
I believe this resolves this ticket, but was unable to prove it directly with the provided information. However, this does solve a specific, input dependent, bug that would result in the described error.
The original implementation of the comparator was generating microseconds since epoch as Longs from the provided packets (seconds * 1000000 + microseconds). While Long is sufficient for holding these values, a narrowing conversion occurs during the intValue() call on the difference. The problem is that narrowing conversions do not necessarily maintain sign. This can then result in incorrect comparisons and the error seen. See http://docs.oracle.com/javase/specs/jls/se8/html/jls-5.html#jls-5.1.3
> A narrowing conversion of a signed integer to an integral type T simply discards all but the n lowest order bits, where n is the number of bits used to represent type T. In addition to a possible loss of information about the magnitude of the numeric value, this may cause the sign of the resulting value to differ from the sign of the input value.
The code has been updated and cleaned up a bit to avoid this narrowing conversion and avoid some unnecessary boxing while I was already in the code. Given that it has plain longs, rather than calculate a difference, it just calls `Long.compare()` on the generated microseconds since epoch. Debug message is modified accordingly to not use the difference anymore, because it's no longer calculated or used.
Unit tests are added, and the original function fails `testLargeDifference()`, while the new one succeeds. This function adds twenty years to the original date, and does a comparison. `compare(earlier, later)` should return negative, but due to the narrowing conversion actually return positive as demonstrated here:
> p1time:1469521273000000 p2time: 2100673273999999 delta: -631152000999999
-631152000999999 - After longValue()
2033081793 - After intValue()
I haven't run this up in a dev environment, given the relatively small size of the change and the ability to directly unit test and prove the error. If anyone wants me to run it up and do more involved testing, I'm happy to do that too.
You can merge this pull request into a Git repository by running:
$ git pull https://github.com/justinleet/incubator-metron METRON-443
Alternatively you can review and apply these changes as the patch at:
https://github.com/apache/incubator-metron/pull/321.patch
To close this pull request, make a commit to your master/trunk branch
with (at least) the following in the commit message:
This closes #321
----
commit 1feb815869f3e0a3ffffcfdbc7b79fc26d645caf
Author: justinjleet <ju...@gmail.com>
Date: 2016-10-25T13:44:55Z
Fixing intValue call to use long comparator
----
> Exception seen while running stellar or fixed query on pcap data
> ----------------------------------------------------------------
>
> Key: METRON-443
> URL: https://issues.apache.org/jira/browse/METRON-443
> Project: Metron
> Issue Type: Bug
> Affects Versions: 0.2.2BETA
> Reporter: Neha Sinha
> Fix For: 0.2.2BETA
>
>
> I am noticing the following exception once in a while when i run the pcap stellar/fixed query.
> Console Log error
> =========================================================
> root@metron-multi-3 ~# /usr/metron/0.2.0BETA/bin/pcap_query.sh fixed -st "20160726" -df "yyyyMMdd" -sa "192.168.138.158" -da "62.75.195.236" -sp "49184" -dp "80" -p "6"
> 16/07/29 06:50:54 INFO impl.TimelineClientImpl: Timeline service address: http://metron-multi-8.openstacklocal:8188/ws/v1/timeline/
> 16/07/29 06:50:54 INFO client.RMProxy: Connecting to ResourceManager at metron-multi-2.openstacklocal/172.22.104.43:8050
> 16/07/29 06:50:56 INFO input.FileInputFormat: Total input paths to process : 17
> 16/07/29 06:50:56 INFO mapreduce.JobSubmitter: number of splits:17
> 16/07/29 06:50:57 INFO mapreduce.JobSubmitter: Submitting tokens for job: job_1469678414974_0019
> 16/07/29 06:50:57 INFO impl.YarnClientImpl: Submitted application application_1469678414974_0019
> 16/07/29 06:50:57 INFO mapreduce.Job: The url to track the job: http://metron-multi-2.openstacklocal:8088/proxy/application_1469678414974_0019/
> 16/07/29 06:50:57 INFO mapreduce.Job: Running job: job_1469678414974_0019
> 16/07/29 06:51:09 INFO mapreduce.Job: Job job_1469678414974_0019 running in uber mode : false
> 16/07/29 06:51:09 INFO mapreduce.Job: map 0% reduce 0%
> 16/07/29 06:51:19 INFO mapreduce.Job: map 12% reduce 0%
> 16/07/29 06:51:22 INFO mapreduce.Job: map 24% reduce 0%
> 16/07/29 06:51:23 INFO mapreduce.Job: map 41% reduce 0%
> 16/07/29 06:51:24 INFO mapreduce.Job: map 53% reduce 0%
> 16/07/29 06:51:25 INFO mapreduce.Job: map 59% reduce 0%
> 16/07/29 06:51:26 INFO mapreduce.Job: map 71% reduce 0%
> 16/07/29 06:51:30 INFO mapreduce.Job: map 76% reduce 0%
> 16/07/29 06:51:32 INFO mapreduce.Job: map 82% reduce 0%
> 16/07/29 06:51:34 INFO mapreduce.Job: map 88% reduce 0%
> 16/07/29 06:51:35 INFO mapreduce.Job: map 100% reduce 0%
> 16/07/29 06:51:36 INFO mapreduce.Job: map 100% reduce 100%
> 16/07/29 06:51:36 INFO mapreduce.Job: Job job_1469678414974_0019 completed successfully
> 16/07/29 06:51:36 INFO mapreduce.Job: Counters: 50
> File System Counters
> FILE: Number of bytes read=60586
> FILE: Number of bytes written=2582180
> FILE: Number of read operations=0
> FILE: Number of large read operations=0
> FILE: Number of write operations=0
> HDFS: Number of bytes read=1936634
> HDFS: Number of bytes written=62671
> HDFS: Number of read operations=71
> HDFS: Number of large read operations=0
> HDFS: Number of write operations=2
> Job Counters
> Launched map tasks=17
> Launched reduce tasks=1
> Data-local map tasks=16
> Rack-local map tasks=1
> Total time spent by all maps in occupied slots (ms)=489258
> Total time spent by all reduces in occupied slots (ms)=40128
> Total time spent by all map tasks (ms)=163086
> Total time spent by all reduce tasks (ms)=13376
> Total vcore-seconds taken by all map tasks=163086
> Total vcore-seconds taken by all reduce tasks=13376
> Total megabyte-seconds taken by all map tasks=200432694
> Total megabyte-seconds taken by all reduce tasks=16439104
> Map-Reduce Framework
> Map input records=2971
> Map output records=260
> Map output bytes=59956
> Map output materialized bytes=60682
> Input split bytes=3264
> Combine input records=0
> Combine output records=0
> Reduce input groups=95
> Reduce shuffle bytes=60682
> Reduce input records=260
> Reduce output records=260
> Spilled Records=520
> Shuffled Maps =17
> Failed Shuffles=0
> Merged Map outputs=17
> GC time elapsed (ms)=4115
> CPU time spent (ms)=19170
> Physical memory (bytes) snapshot=8603783168
> Virtual memory (bytes) snapshot=42252124160
> Total committed heap usage (bytes)=6922698752
> Shuffle Errors
> BAD_ID=0
> CONNECTION=0
> IO_ERROR=0
> WRONG_LENGTH=0
> WRONG_MAP=0
> WRONG_REDUCE=0
> File Input Format Counters
> Bytes Read=1933370
> File Output Format Counters
> Bytes Written=62671
> Exception in thread "main" java.lang.IllegalArgumentException: Comparison method violates its general contract!
> at java.util.TimSort.mergeHi(TimSort.java:895)
> at java.util.TimSort.mergeAt(TimSort.java:512)
> at java.util.TimSort.mergeCollapse(TimSort.java:435)
> at java.util.TimSort.sort(TimSort.java:241)
> at java.util.Arrays.sort(Arrays.java:1512)
> at java.util.ArrayList.sort(ArrayList.java:1454)
> at java.util.Collections.sort(Collections.java:175)
> at org.apache.metron.pcap.PcapMerger.sort(PcapMerger.java:165)
> at org.apache.metron.pcap.PcapMerger.merge(PcapMerger.java:110)
> at org.apache.metron.pcap.query.ResultsWriter.mergePcaps(ResultsWriter.java:45)
> at org.apache.metron.pcap.query.ResultsWriter.write(ResultsWriter.java:33)
> at org.apache.metron.pcap.query.PcapCli.run(PcapCli.java:149)
> at org.apache.metron.pcap.query.PcapCli.main(PcapCli.java:46)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at org.apache.hadoop.util.RunJar.run(RunJar.java:221)
> at org.apache.hadoop.util.RunJar.main(RunJar.java:136)
> ========================================================
> PCAP Contents
> ========================================================
> root@metron-multi-3 ~# /usr/metron/0.2.0BETA/bin/pcap_inspector.sh -i /apps/metron/pcap/pcap_pcap_1469521273134478000_0_e05b4319-6498-4dce-bee2-02f0e1e28755 -n 5
> TS: July 26, 2016 8:21:13 AM UTC,ip_src_addr: 172.22.80.156,ip_src_port: 44324,ip_dst_addr: 172.22.80.228,ip_dst_port: 6667,protocol: 6
> TS: July 26, 2016 8:21:13 AM UTC,ip_src_addr: 172.22.80.156,ip_src_port: 44324,ip_dst_addr: 172.22.80.228,ip_dst_port: 6667,protocol: 6
> TS: July 26, 2016 8:21:13 AM UTC,ip_src_addr: 172.22.80.156,ip_src_port: 44324,ip_dst_addr: 172.22.80.228,ip_dst_port: 6667,protocol: 6
> TS: July 26, 2016 8:21:13 AM UTC,ip_src_addr: 172.22.80.228,ip_src_port: 6667,ip_dst_addr: 172.22.80.156,ip_dst_port: 44324,protocol: 6
> TS: July 26, 2016 8:21:13 AM UTC,ip_src_addr: 172.22.80.156,ip_src_port: 44324,ip_dst_addr: 172.22.80.228,ip_dst_port: 6667,protocol: 6
> ========================================================
> Fixed Query
> ========================================================
> /usr/metron/0.2.0BETA/bin/pcap_query.sh fixed -st "20160726" -df "yyyyMMdd" -sa "172.22.80.156" -da "172.22.80.228" -sp "6667" -dp "44324" -p “6"
> ========================================================
> Stellar Query
> ========================================================
> /usr/metron/0.2.0BETA/bin/pcap_query.sh query -st "20160726" -df "yyyyMMdd" -query "ip_src_addr == '172.22.80.156' and ip_dst_addr == '172.22.80.228' and ip_src_port == '6667' ip_dst_port == '4432' and protocol== '6'"
> ========================================================
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)