Closed lsadehaan closed 4 years ago
lmangani
commented
4 years ago Hi there! HOMER should return any association (RTCP, Logs, etc) as long as the rules are not broken, so I suppose you did nothing wrong. In order to get assistance you have to be as precise as possible.
I have checked the database and I can see the RTPC data in the hep_proto_5_default table. Let's see a query with a few of those as a starter please.
lsadehaan
commented
4 years ago Not sure the best way to post it here, but here goes:
SELECT "id"
,"sid"
,"create_date"
,"protocol_header"
,"data_header"
,"raw"
FROM "public"."hep_proto_5_default" LIMIT 5returns:
1 958a061a-e61c-1238-5c9d-d21172234705 2020-03-21 13:42:05.8472550 +00:00 {"dstIp": "xx.xx.xx.xxx", "srcIp": "xx.xx.xx.xxx", "dstPort": 25893, "srcPort": 37421, "protocol": 17, "captureId": "2002", "payloadType": 5, "timeSeconds": 1584798125, "timeUseconds": 847255, "correlation_id": "958a061a-e61c-1238-5c9d-d21172234705", "protocolFamily": 2} {"node": "2002", "proto": "rtcp"} {"sender_information":{"ntp_timestamp_sec":4,"ntp_timestamp_usec":773062656,"rtp_timestamp":875626184,"packets":209,"octets":33440},"ssrc":987103888,"type":202,"report_count":1,"report_blocks":[{"source_ssrc":2927414809,"fraction_lost":0,"packets_lost":0,"highest_seq_no":38345,"ia_jitter":6,"lsr":0,"dlsr":0}],"report_blocks_xr":{"type":7,"id":2927414809,"fraction_lost":0,"fraction_discard":0,"burst_density":0,"gap_density":0,"burst_duration":0,"gap_duration":3300,"round_trip_delay":0,"end_system_delay":0},"sdes_ssrc":987103888}
2 07076f89-e61d-1238-5c9d-d21172234705 2020-03-21 13:45:14.1955850 +00:00 {"dstIp": "xx.xx.xx.xxx", "srcIp": "xx.xx.xx.xxx", "dstPort": 31281, "srcPort": 24149, "protocol": 17, "captureId": "2002", "payloadType": 5, "timeSeconds": 1584798314, "timeUseconds": 195585, "correlation_id": "07076f89-e61d-1238-5c9d-d21172234705", "protocolFamily": 2} {"node": "2002", "proto": "rtcp"} {"sender_information":{"ntp_timestamp_sec":1,"ntp_timestamp_usec":4251975680,"rtp_timestamp":2639216120,"packets":99,"octets":15840},"ssrc":139736201,"type":202,"report_count":1,"report_blocks":[{"source_ssrc":2927378423,"fraction_lost":0,"packets_lost":0,"highest_seq_no":23789,"ia_jitter":1,"lsr":0,"dlsr":0}],"report_blocks_xr":{"type":7,"id":2927378423,"fraction_lost":0,"fraction_discard":0,"burst_density":0,"gap_density":0,"burst_duration":0,"gap_duration":200,"round_trip_delay":0,"end_system_delay":0},"sdes_ssrc":139736201}
3 07076f89-e61d-1238-5c9d-d21172234705 2020-03-21 13:45:19.1956210 +00:00 {"dstIp": "xx.xx.xx.xxx", "srcIp": "xx.xx.xx.xxx", "dstPort": 31281, "srcPort": 24149, "protocol": 17, "captureId": "2002", "payloadType": 5, "timeSeconds": 1584798319, "timeUseconds": 195621, "correlation_id": "07076f89-e61d-1238-5c9d-d21172234705", "protocolFamily": 2} {"node": "2002", "proto": "rtcp"} {"sender_information":{"ntp_timestamp_sec":6,"ntp_timestamp_usec":4251975680,"rtp_timestamp":2639256120,"packets":349,"octets":55840},"ssrc":139736201,"type":202,"report_count":1,"report_blocks":[{"source_ssrc":2927378423,"fraction_lost":0,"packets_lost":0,"highest_seq_no":24033,"ia_jitter":2,"lsr":0,"dlsr":0}],"report_blocks_xr":{"type":7,"id":2927378423,"fraction_lost":0,"fraction_discard":0,"burst_density":0,"gap_density":0,"burst_duration":0,"gap_duration":5080,"round_trip_delay":0,"end_system_delay":0},"sdes_ssrc":139736201}
4 07076f89-e61d-1238-5c9d-d21172234705 2020-03-21 13:45:24.1960060 +00:00 {"dstIp": "xx.xx.xx.xxx", "srcIp": "xx.xx.xx.xxx", "dstPort": 31281, "srcPort": 24149, "protocol": 17, "captureId": "2002", "payloadType": 5, "timeSeconds": 1584798324, "timeUseconds": 196006, "correlation_id": "07076f89-e61d-1238-5c9d-d21172234705", "protocolFamily": 2} {"node": "2002", "proto": "rtcp"} {"sender_information":{"ntp_timestamp_sec":11,"ntp_timestamp_usec":4251975680,"rtp_timestamp":2639296120,"packets":599,"octets":95840},"ssrc":139736201,"type":202,"report_count":1,"report_blocks":[{"source_ssrc":2927378423,"fraction_lost":0,"packets_lost":0,"highest_seq_no":24277,"ia_jitter":5,"lsr":0,"dlsr":0}],"report_blocks_xr":{"type":7,"id":2927378423,"fraction_lost":0,"fraction_discard":0,"burst_density":0,"gap_density":0,"burst_duration":0,"gap_duration":9960,"round_trip_delay":0,"end_system_delay":0},"sdes_ssrc":139736201}
5 07076f89-e61d-1238-5c9d-d21172234705 2020-03-21 13:45:29.1956020 +00:00 {"dstIp": "xx.xx.xx.xxx", "srcIp": "xx.xx.xx.xxx", "dstPort": 31281, "srcPort": 24149, "protocol": 17, "captureId": "2002", "payloadType": 5, "timeSeconds": 1584798329, "timeUseconds": 195602, "correlation_id": "07076f89-e61d-1238-5c9d-d21172234705", "protocolFamily": 2} {"node": "2002", "proto": "rtcp"} {"sender_information":{"ntp_timestamp_sec":16,"ntp_timestamp_usec":4251975680,"rtp_timestamp":2639336120,"packets":849,"octets":135840},"ssrc":139736201,"type":202,"report_count":1,"report_blocks":[{"source_ssrc":2927378423,"fraction_lost":0,"packets_lost":0,"highest_seq_no":24523,"ia_jitter":5,"lsr":0,"dlsr":0}],"report_blocks_xr":{"type":7,"id":2927378423,"fraction_lost":0,"fraction_discard":0,"burst_density":0,"gap_density":0,"burst_duration":0,"gap_duration":14880,"round_trip_delay":0,"end_system_delay":0},"sdes_ssrc":139736201}I am not able to see any RTCP packets in the UI
lsadehaan
commented
4 years ago My heplify-server logs:
# docker logs 39ccd1a980cd --tail=2000 -f
Could not find toml config file, use flag defaults. <nil>
2020/03/21 13:35:50.008968 server.go:83: INFO start heplify-server 1.26 with config.HeplifyServer{HEPAddr:"0.0.0.0:9060", HEPTCPAddr:"", HEPTLSAddr:"0.0.0.0:9061", ESAddr:"", ESDiscovery:true, ESUser:"", ESPass:"", LokiURL:"http://loki:3100/api/prom/push", LokiBulk:400, LokiTimer:2, LokiBuffer:100000, LokiHEPFilter:[]int{1, 5, 100}, ForceHEPPayload:[]int(nil), PromAddr:"0.0.0.0:9096", PromTargetIP:"", PromTargetName:"", DBShema:"homer7", DBDriver:"postgres", DBAddr:"db:5432", DBUser:"root", DBPass:"homerSeven", DBDataTable:"homer_data", DBConfTable:"homer_config", DBBulk:400, DBTimer:4, DBBuffer:400000, DBWorker:8, DBRotate:true, DBPartLog:"2h", DBPartIsup:"6h", DBPartSip:"2h", DBPartQos:"6h", DBDropDays:5, DBDropDaysCall:0, DBDropDaysRegister:0, DBDropDaysDefault:0, DBDropOnStart:false, Dedup:false, DiscardMethod:[]string(nil), AlegIDs:[]string(nil), CustomHeader:[]string(nil), SIPHeader:[]string{"ruri_user", "ruri_domain", "from_user", "from_tag", "to_user", "callid", "cseq", "method", "user_agent"}, LogDbg:"", LogLvl:"info", LogStd:true, LogSys:false, Config:"./heplify-server.toml", ConfigHTTPAddr:"", ConfigHTTPPW:"", Version:false}
2020/03/21 13:35:50.009216 prometheus.go:38: INFO expose metrics without or unbalanced targets
2020/03/21 13:35:50.010437 server.go:121: ERR Get "http://loki:3100/loki/api/v1/label": dial tcp 172.19.0.2:3100: connect: connection refused
2020/03/21 13:35:52.013872 rotator.go:394: WARN pq: database "homer_data" already exists
2020/03/21 13:35:52.014098 rotator.go:394: WARN pq: role "homer_user" already exists
2020/03/21 13:35:52.014294 rotator.go:394: WARN pq: role "postgres" does not exist
2020/03/21 13:35:52.055649 rotator.go:332: INFO start creating tables (2020-03-21 13:35:52.055636033 +0000 UTC m=+2.051743596)
2020/03/21 13:35:52.213299 rotator.go:345: INFO end creating tables (2020-03-21 13:35:52.213292375 +0000 UTC m=+2.209399929)
2020/03/21 13:35:52.215067 postgres.go:61: INFO postgres connection established
2020/03/21 13:40:50.009834 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 0, Filtered: 0, Error: 0
2020/03/21 13:45:50.009661 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 125, Filtered: 0, Error: 0
2020/03/21 13:50:50.009496 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 98, Filtered: 0, Error: 0
2020/03/21 13:55:50.009753 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 89, Filtered: 0, Error: 0
2020/03/21 14:00:50.009791 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 91, Filtered: 0, Error: 0
2020/03/21 14:05:50.009735 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 89, Filtered: 0, Error: 0
2020/03/21 14:10:50.009573 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 88, Filtered: 0, Error: 0
2020/03/21 14:15:50.009636 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 89, Filtered: 0, Error: 0
2020/03/21 14:20:50.009544 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 91, Filtered: 0, Error: 0
2020/03/21 14:25:50.009646 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 88, Filtered: 0, Error: 0
2020/03/21 14:30:50.009684 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 91, Filtered: 0, Error: 0
2020/03/21 14:35:50.009634 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 87, Filtered: 0, Error: 0
2020/03/21 14:40:50.009628 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 90, Filtered: 0, Error: 0
2020/03/21 14:45:50.009620 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 88, Filtered: 0, Error: 0
2020/03/21 14:50:50.009763 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 92, Filtered: 0, Error: 0
2020/03/21 14:55:50.009570 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 88, Filtered: 0, Error: 0
2020/03/21 15:00:50.009686 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 89, Filtered: 0, Error: 0
2020/03/21 15:05:50.009678 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 90, Filtered: 0, Error: 0
2020/03/21 15:10:50.009718 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 90, Filtered: 0, Error: 0
2020/03/21 15:15:50.009774 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 88, Filtered: 0, Error: 0
2020/03/21 15:20:50.009662 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 90, Filtered: 0, Error: 0
2020/03/21 15:25:50.009657 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 84, Filtered: 0, Error: 0
2020/03/21 15:30:50.009658 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 88, Filtered: 0, Error: 0
2020/03/21 15:35:50.009541 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 90, Filtered: 0, Error: 0
2020/03/21 15:40:50.009667 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 90, Filtered: 0, Error: 0
2020/03/21 15:45:50.009673 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 89, Filtered: 0, Error: 0
2020/03/21 15:50:50.009650 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 91, Filtered: 0, Error: 0
2020/03/21 15:55:50.009523 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 89, Filtered: 0, Error: 0
2020/03/21 16:00:50.009505 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 90, Filtered: 0, Error: 0
2020/03/21 16:05:50.009651 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 85, Filtered: 0, Error: 0
2020/03/21 16:10:50.009656 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 90, Filtered: 0, Error: 0
2020/03/21 16:15:50.009759 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 88, Filtered: 0, Error: 0
2020/03/21 16:20:50.009768 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 86, Filtered: 0, Error: 0
2020/03/21 16:25:50.009590 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 89, Filtered: 0, Error: 0
2020/03/21 16:30:50.009702 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 85, Filtered: 0, Error: 0
2020/03/21 16:35:50.009561 server.go:242: INFO stats since last 5 minutes. PPS: 0, HEP: 85, Filtered: 0, Error: 0And for the web app:
Version: homer-app 1.1.37
⇨ http server started on [::]:80
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_100_call\" does not exist","time":"2020-03-21T13:42:20Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_5_call\" does not exist","time":"2020-03-21T13:42:20Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_100_call\" does not exist","time":"2020-03-21T13:42:39Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_5_call\" does not exist","time":"2020-03-21T13:42:39Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_100_call\" does not exist","time":"2020-03-21T13:42:48Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_5_call\" does not exist","time":"2020-03-21T13:42:48Z"}
{"level":"error","msg":"Couldn't make http query:http://loki:3100/loki/api/v1/query_range?end=1584798179000000000\u0026limit=100\u0026query=%7Bjob%3D%22heplify-server%22%7D\u0026regexp=58844c3-e61c-1238-dd85-a2f1f7ae1a0c\u0026start=1584794579000000000","time":"2020-03-21T13:43:01Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_100_call\" does not exist","time":"2020-03-21T13:43:55Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_5_call\" does not exist","time":"2020-03-21T13:43:55Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_100_call\" does not exist","time":"2020-03-21T13:44:04Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_5_call\" does not exist","time":"2020-03-21T13:44:04Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_100_call\" does not exist","time":"2020-03-21T13:46:38Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_5_call\" does not exist","time":"2020-03-21T13:46:38Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_100_call\" does not exist","time":"2020-03-21T13:47:09Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_5_call\" does not exist","time":"2020-03-21T13:47:09Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_100_call\" does not exist","time":"2020-03-21T16:30:32Z"}
{"level":"error","msg":"GetTransactionData: We have got error: pq: relation \"hep_proto_5_call\" does not exist","time":"2020-03-21T16:30:32Z"}I managed to get the RTCP to show by modifying the mapping of the "call" profile, I changed "call" profile for SIP to have the following (changed "call" to "default" for the lookup_profile):
{
"source_field": "data_header.callid",
"lookup_id": 5,
"lookup_profile": "default",
"lookup_field": "sid",
"lookup_range": [
-300,
200
]
},I think this is probably just obscuring the root problem - but for now I can see the RTCP packets again. I don't really understand what these profiles mean etc. - where can I learn more about these mappings and what everything means and how/where they get categorized?
lmangani
commented
4 years ago The profiles are used to split transactions types such as calls, registrations, or others. This clearly only applies to session protocols, while others only present the default profile. Its a dynamic association.
We'll take a look and try to confirm if this is a general or specific issue next.
githubsesui
commented
4 years ago I have the same problem with the UI not showing any traffic. It used to show traffic 2 weeks ago before I went on a holiday. Traffic is being sent to Homer from 6 asterisk servers
and it is listening on port 9060. I don't see traffic being displayed even for the days before I went on a holiday such as 6th March 2020.
githubsesui
commented
4 years ago How can I check if traffic is being logged on homer but not showing on the UI?
lsadehaan
commented
4 years ago How can I check if traffic is being logged on homer but not showing on the UI?
If you are using the docker-compose based installation, I'd recommend configuring the database container to expose the postgres port so you can connect to it from outside of docker - like this:
Then install some client to access postgres database - pgadmin is a good option. https://www.pgadmin.org/ or dbeaver which is maybe a bit easier to use https://dbeaver.io/
Then connect to the DB - homer_data contains the data captured and homer_config contains config data. The following would return RTCP data (from homer_data).
SELECT "id"
,"sid"
,"create_date"
,"protocol_header"
,"data_header"
,"raw"
FROM "public"."hep_proto_5_default" LIMIT 50How can I check if traffic is being logged on homer but not showing on the UI?
If you are using the docker-compose based installation, I'd recommend configuring the database container to expose the postgres port so you can connect to it from outside of docker - like this:
Then connect to the DB - homer_data contains the data captured and homer_config contains config data. The following would return RTCP data (from homer_data).
SELECT "id" ,"sid" ,"create_date" ,"protocol_header" ,"data_header" ,"raw" FROM "public"."hep_proto_5_default" LIMIT 50
Thank you for the info above. It looks like the troubleshooting uncovered the cause. After I rebooted the server the postgresql-12.service did not start with the error below.
The following directory "/var/lib/pgsql/12/data/base" filled up the whole partition
So it looks like the database has grown so large that the partition /dev/mapper/centos_homer-root is 100% full.
What would be the best way to free space if I don't need the data in the database? I assume I can't delete the folder without impacting the DB install.
lmangani
commented
4 years ago @githubsesui it seems the setup was undersized or misconfigured. If you dont need the data drop the postgres container and its volumes and start fresh minding to have a small(er) retention period.
githubsesui
commented
4 years ago @githubsesui it seems the setup was undersized or misconfigured. If you dont need the data drop the postgres container and its volumes and start fresh minding to have a small(er) retention period.
Imangani, thank you for the reply.
Homer 7.7 was installed with the quick-install script.
looking at the documentation, there is a "heplify-server.toml" configuration file with a variable called "DBDropDays". I just can't find the file location on the filesystem. I'd like to try to reduce the DBDropDays parameter and also change the "DBDropOnStart" to "true" to see if that will release space and start the postgresql-12 service.
Would that work to start HOMER to work as before without reinstalling everything? Could I get the locations of the "heplify-server.toml" configuration file?
I understand that I will have to resize the partition as it looks like the space is not enough for the volume we want to process, but it will be better if I manage to get it to work first as before.
lmangani
commented
4 years ago If you deployed using packages, the file should be in /etc/heplify-server.toml
If you restart with different settings, the drop MIGHT work assuming the volume is not already locked.
Feel free to extend the topic here if you need assistance but this no longer seems related to RTCP
I am quite new to Homer so I might be doing or understanding something wrong, but I think there is a bug in the UI not showing the RTPC data.
My setup: Server: installed hom7-prom-all docker-compose setup Capture: heplify -hs:9060 -e
I have checked the database and I can see the RTCP data in the hep_proto_5_default table.
I have checked the web app interface and I see the following two requests:
http://10.15.0.28:9080/api/v3/mapping/protocolThis returns 7 JSON objects, it seems to contain information for each protocol type in the database, but does not contain any information for RTCP nor anything with ID=5.http://10.15.0.28:9080/api/v3/search/call/data{"param":{"transaction":{},"limit":200,"search":{"1_call":[]},"location":{},"timezone":{"value":-180,"name":"Local"}},"timestamp":{"from":1584788859000,"to":1584799659000}}The response again doesn't seem to contain any RTCP or protocol:5 or anything of the kind.
At one stage I saw some RTCP packets, but that was for a short while and I am not sure what I have done before or after that made it appear/disappear. I have also re-installed on a different server to see if it makes any difference, but it made no difference.
Any help greatly appreciated!