sipcapture / homer

HOMER - 100% Open-Source SIP, VoIP, RTC Packet Capture & Monitoring
https://sipcapture.org
GNU Affero General Public License v3.0
1.64k stars 242 forks source link

Blank / Empty Call Flows w/ Remote DB #197

Closed shaunbro closed 4 years ago

shaunbro commented 8 years ago

I can see that there are several reports for this, I have read all of these and have not been able to resolve my issue. Search results return successfully although I feel like the time selection is often not working as expected. When I click on anything (call-id, method) I get a blank window. Calls for the previous day still display correctly.

Full disclosure the last comment I saw on an earlier issue references docker and I am running homer from docker containers. (MSG ID window is blank #142). The comment suggests that NTP or time sync is an issue, I would just like to understand why? the clocks on these containers are all in sync with the box running the captureagent.

(should add, running latest build from the manual installer script - Kamailio 4.4.3)

thanks.

dougbtv commented 8 years ago

Shaunbro, feel free to open an issue on sipcapture/docker if relative to that, it should be version pinned in those containers and I can take a look there too.

I, too, have noticed that sometimes I feel like i have had to look at a different time range.

The homer docker project does have a series of CI tests to pass which ensure it can pick up HEP and stores it in the database however it does not include any tests for the web UI outside of it seeing that the webserver returns a 200 saying it's alive. If it's a UI issue I may be of somewhat less help.

On Thu, Nov 3, 2016, 9:44 PM shaunbro notifications@github.com wrote:

I can see that there are several reports for this, I have read all of these and have not been able to resolve my issue. Search results return successfully although I feel like the time selection is often not working as expected. When I click on anything (call-id, method) I get a blank window. Calls for the previous day still display correctly.

Full disclosure the last comment I saw on an earlier issue references docker and I am running homer from docker containers. (MSG ID window is blank #142 https://github.com/sipcapture/homer/issues/142). The comment suggests that NTP or time sync is an issue, I would just like to understand why? the clocks on these containers are all in sync with the box running the captureagent.

thanks.

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/sipcapture/homer/issues/197, or mute the thread https://github.com/notifications/unsubscribe-auth/AFN_vZbkGAELXN705lJri1DoISjawIFEks5q6o3ygaJpZM4KpHEK .

shaunbro commented 8 years ago

Thanks Doug, I am actually not using the container because it wasn't working every time I have previously tested. I can see that it is now passing build so may try it again.

The issue seems to be for particular calls only now, but given I have made several changes (one of the suggested kamailio.cfg changes in the FAQ) I am not at all clear what is broken, if anything I did fixed it and how to avoid it. New calls now appear to be visible but older calls are still showing blank.

adubovikov commented 8 years ago

if you activate the syslog param in the preferences.php, can you please check the sql query and timestamp ?

shaunbro commented 7 years ago

Here is the query (I have redacted IP's and phone numbers as they are not mine)

Interestingly the last OR correlation_id test drops the last digit of the IP as in 1.2.3.123 becomes 1.2.3.12 (this was not done by mistake in my redaction of details)

Nov 6 18:35:31 homer2 homerlog[341]: get rtcp for transaction data: SELECT *,'single' as dbnode,UNIX_TIMESTAMP(date) as unixts FROM webrtc_capture WHERE (date BETWEEN FROM_UNIXTIME(1478219017) AND FROM_UNIXTIME(1478300205)) AND ( ( correlation_id = '1234@1.2.3.123' OR correlation_id = '1234@1.2.3.123_b2b-1' OR correlation_id = '1234@1.2.3.123_b2b-' OR correlation_id = '1234@1.2.3.12' )) LIMIT 100 Nov 6 18:35:31 homer2 homerlog[341]: get messages for transaction data: SELECT id, date, (micro_ts DIV 1000) as milli_ts, micro_ts,method,reply_reason,ruri,ruri_user,ruri_domain,from_user,from_domain,from_tag,#012to_user,to_domain,to_tag,pid_user,contact_user,auth_user,callid,callid_aleg,via_1,via_1_branch,cseq,diversion,reason,content_type,auth,#012user_agent,source_ip,source_port,destination_ip,destination_port,contact_ip,contact_port,originator_ip,originator_port,correlation_id,proto,family,rtp_stat,type,node,'call' as trans,'single' as dbnode,msg FROM sip_capture_call_20161104 WHERE (date BETWEEN FROM_UNIXTIME(1478219017) AND FROM_UNIXTIME(1478300145)) AND ( ( callid = '1234@1.2.3.123' OR callid = '1234@1.2.3.123_b2b-1')) LIMIT 200 Nov 6 18:36:23 homer2 homerlog[335]: method query: SELECT id, date, (micro_ts DIV 1000) as milli_ts, micro_ts,method,reply_reason,ruri,ruri_user,ruri_domain,from_user,from_domain,from_tag,#012to_user,to_domain,to_tag,pid_user,contact_user,auth_user,callid,callid_aleg,via_1,via_1_branch,cseq,diversion,reason,content_type,auth,#012user_agent,source_ip,source_port,destination_ip,destination_port,contact_ip,contact_port,originator_ip,orig

shaunbro commented 7 years ago

Also for clarity as this is perhaps not usual, I am in a different time zone to the hardware, so my local time != homer local time

SipSeb commented 7 years ago

We are having the same problem, but sending the search query from an external website. It depends on the time range selected in Homer whether you see the call flow or not.

Example:

I enabled the syslog parameter, and I can see the query being executed when submitting the search from the external website, but nothing happens in the log when clicking on a Call-ID. So I don't know whether logging helps in this case.

lmangani commented 7 years ago

Are you also sending the timerange with the "external" search query? (which I assume uses the Rison parameters)

SipSeb commented 7 years ago

Yes of course. This is what the query in syslog looks like:

Nov 11 16:49:55 barnitz homerlog[21625]: Search query: SELECT id, date, (micro_ts DIV 1000) as milli_ts, 
  micro_ts,method,reply_reason,ruri,ruri_user,ruri_domain,from_user,from_domain,from_tag, to_user,to_domain,
  to_tag,pid_user,contact_user,auth_user,callid,callid_aleg,via_1,via_1_branch,cseq,diversion,reason,content_type,auth, 
  user_agent,source_ip,source_port,destination_ip,destination_port,contact_ip,contact_port,originator_ip,
  originator_port,correlation_id,proto,family,rtp_stat,type,node,'call' as trans,'homer01' as dbnode 
  FROM sip_capture_call_20161110 as t  WHERE (t.date BETWEEN FROM_UNIXTIME(1478803174)
  AND FROM_UNIXTIME(1478803237)) AND ( ( from_user = '49176xxxxxxx' OR from_user = '0049176xxxxxxx' 
  OR from_user = '+49176xxxxxxx' OR from_user = '1234567p123' OR from_user = '0176xxxxxxxx' ) 
  OR ( ruri_user = '49163xxxxxxx' OR ruri_user = '0049163xxxxxxx' OR ruri_user = '+49163xxxxxxx' 
  OR ruri_user = '1234567p123' ) OR ( pid_user = '49176xxxxxxx' OR pid_user = '0049176xxxxxxx' 
  OR pid_user = '+49176xxxxxxx' )) LIMIT 100
adubovikov commented 7 years ago

and what do you have in the RISON query ?

lmangani commented 7 years ago

I guess your timestamp does not account for timezone or something similar. As @adubovikov said we need to see both query and results to establish so.

SipSeb commented 7 years ago

I don't know what the RISON query is. But we trigger the search from external through this form:

<form target="_blank" method="GET" action="https://homer.sipgate.net/#/result?query=
  (trancall:'true',startts:'1478803174',endts:'1478803237',search_orand:'true',
  search_ruri_user:'49163xxxxxxx%3B0049163xxxxxxx
  %3B%2B49163xxxxxxx%3B1234567p123',
  search_from_user:'49176xxxxxxx%3B0049176xxxxxxx
%3B%2B49176xxxxxxx%3B1234567p123%3B0176xxxxxxx',
  search_pid_user:'49176xxxxxxx%3B0049176xxxxxxx%3B%2B49176xxxxxxx')" 
  style="display: inline;">

If you wanted to see a query that appears when clicking on the Call-ID, I don't have it. It doesn't appear in syslog.

lmangani commented 7 years ago

@SipSeb check if the starttts and endts correspond to what you would expect in the query please

SipSeb commented 7 years ago

The times in those two fields are fine. And the search results show the correct packets. Only the call flow doesn't find anything.

I just queried the same call again, used ngrep to see what was actually happening, and in the original query issued when entering from the external website, the following time is used: WHERE (t.date BETWEEN FROM_UNIXTIME(1478803174) AND FROM_UNIXTIME(1478803237))

The times are:

Then when clicking on the Call-ID, the following query is issued:

SELECT t.*, 'call' as trans,'homer01' as dbnode FROM sip_capture_call_20161110 as t WHERE 
  (t.date BETWEEN FROM_UNIXTIME(1478802584) AND FROM_UNIXTIME(1478796067)) AND 
  ( ( callid = '609385eb02003f53400fd8d570f01c18@sipgate.de' OR 
  callid = '609385eb02003f53400fd8d570f01c18@sipgate.de_b2b-1')) order by id DESC LIMIT 200

The times used this time are:

Ooops!

After changing the date in the upper right corner and clicking on the Call-ID again, this query is executed:

SELECT t.*, 'call' as trans,'homer01' as dbnode FROM sip_capture_call_20161110 as t WHERE
  (t.date BETWEEN FROM_UNIXTIME(1478802584) AND FROM_UNIXTIME(1478815229)) AND 
  ( ( callid = '609385eb02003f53400fd8d570f01c18@sipgate.de' OR 
  callid = '609385eb02003f53400fd8d570f01c18@sipgate.de_b2b-1')) order by id DESC LIMIT 200

The dates in here are:

There's something happening with the end date in the Call-ID link. It is two hours too early without adjusting the time range, and it is the end of the day (or so) after changing it.

Does this help?

greenfieldtech-nirs commented 7 years ago

Hi All,

I can concur your findings - my installation suffers from the same exact issue. All my systems are set to UTC, while I'm at GMT+2.

Really odd.

adubovikov commented 7 years ago

Hi guys,

can you please check the patch ?

https://github.com/sipcapture/homer-ui/commit/e519fae3717e3d56af2538985118abd8d4ab3003

Wbr, Alexandr

dougbtv commented 7 years ago

I'm not following closely, but just an FYI that the homer/docker dockerfiles version pin the various pieces of homer projects (homer UI, API, etc). I'd love to update that to follow tags in those projects someday.

But in the meanwhile, if a particular commitish solves a bug, we can update it, grep the Dockerfiles for "git clone" and you'll see the pinned versions.

On Sat, Nov 12, 2016, 4:14 AM Alexandr Dubovikov notifications@github.com wrote:

Hi guys,

can you please check the patch ?

sipcapture/homer-ui@e519fae https://github.com/sipcapture/homer-ui/commit/e519fae3717e3d56af2538985118abd8d4ab3003

Wbr, Alexandr

— You are receiving this because you commented.

Reply to this email directly, view it on GitHub https://github.com/sipcapture/homer/issues/197#issuecomment-260111158, or mute the thread https://github.com/notifications/unsubscribe-auth/AFN_vbnHrpcMkktIU7_RSzHHeAbjrzdTks5q9YOJgaJpZM4KpHEK .

greenfieldtech-nirs commented 7 years ago

Nope, the patch doesn't work - actually, now it's worse. Previously, sometimes, I would see the RTCP report - now, that is gone as well.

SipSeb commented 7 years ago

Tried the patch, didn't change anything. The values in the two queries stay the same as written in my last reply.

Earn330 commented 7 years ago

Has there something happened since the last comment, as we have the same problem.

Greetings, Bjoern

shaunbro commented 7 years ago

Update to this, I am back on the container image and recently (last week) pulled the latest image. I now get completed ladder diagrams when I click on CallID but blank windows when I click on any individual MSG ID either directly or under the CallID popup window. The data is clearly there as export functions work correctly. Would love to work out what is going wrong.

(in the interests of full disclosure I am running a somewhat modified container image, I have broken out a lot of the configuration and completely replaced the run shell script, but this is largely just to support a remote DB and data persistence )

Also separate issue but the suggested method for running an external MySQL db doesn't work at all, the reason I ended up completely modifying the run script and breaking out configs from the container is that the DB variables are not correctly passed or used in a lot of places. Happy to provide details or patches.

lmangani commented 7 years ago

Hi @shaunbro were you using the multi-container version or the all-in-one container for this? I'm skeptical about the MySQL part not working as described, would like to understand more in a separate, dedicated ticket please.

adubovikov commented 7 years ago

@shaunbro can you please activate SYSLOG in the preferences.php and paste here the SQL query you get during the popup opening....

Thank you!

shaunbro commented 7 years ago

syslog from popup

Mar 15 07:59:51 homer homerlog[48]: method query: SELECT id, date, (micro_ts DIV 1000) as milli_ts, micro_ts,method,reply_reason,ruri,ruri_user,ruri_domain,from_user,from_domain,from_tag,#012to_user,to_domain,to_tag,pid_user,contact_user,auth_user,callid,callid_aleg,via_1,via_1_branch,cseq,diversion,reason,content_type,auth,#012user_agent,source_ip,source_port,destination_ip,destination_port,contact_ip,contact_port,originator_ip,originator_port,correlation_id,proto,family,rtp_stat,type,node,'call' as trans,'' as dbnode,msg FROM sip_capture_call_20170313 WHERE (date BETWEEN FROM_UNIXTIME(1489449300) AND FROM_UNIXTIME(1489449901)) AND ( id = '7') LIMIT 1

shaunbro commented 7 years ago

not sure if this is relevant but the node values in the DB (settings table) under my user show the following {"node":{"name":"localhost","id":"localhost"},"dbnode":[{"id":"1","name":"homer01"}]}

It is not clear to me what "localhost" is referencing but my DB is not local and is correctly defined under the node

adubovikov commented 7 years ago

and now please show me the result of:

select *, UNIX_TIMESTAMP(date) as unixts from sip_capture_call_20170313 WHERE id = 7\G

shaunbro commented 7 years ago

shows data, unfortunately for a production call so I can't insert. but basically looks like the full ACK details (let me have a go at redacting)

"7","2017-03-13 00:00:00","1489363200396938","ACK",,"sip:user@ip:port;transport=udp","user","IP","CLID","IP","4634cb0c-13c4-58c5e0ff-3db6232-445fee1f","DNIS","IP","ANI",,"CLID",,"BW2000000361203171066996833@IP",,"SIP/2.0/UDP IP:PORT;branch=z9hG4bK-35872e-58c5e0ff-3db637b-3e99da8e","z9hG4bK-35872e-58c5e0ff-3db637b-3e99da8e","1 ACK",,,,,,"IP","PORT","IP","PORT","IP","PORT",,"0","-1","BW2000000361203171066996833@IP",,,,"1","2",,"1","homer01:0","ACK sip:user@ip:port;transport=udp SIP/2.0 From: ""WIRELESS CALLER"" sip:user@ip:port;tag=4634cb0c-13c4-58c5e0ff-3db6232-445fee1f To: ""SomeCompany"" sip:user@ip:port;tag=1200498451 Call-ID: BW2000000361203171066996833@IP CSeq: 1 ACK Via: SIP/2.0/UDP IP:PORT;branch=z9hG4bK-35872e-58c5e0ff-3db637b-3e99da8e Max-Forwards: 70 Contact: sip:CLID@IP:PORT;transport=udp Content-Length: 0

","DNIS"

adubovikov commented 7 years ago

sorry, I don't see the UNIX_TIMESTAMP(date) as unixts can you just run it ?

select UNIX_TIMESTAMP(date) as unixts from sip_capture_call_20170313 WHERE id = 7;

shaunbro commented 7 years ago

Sorry I can see what happened there, here is the timestamp

1489377600

adubovikov commented 7 years ago

I am not sure that something is correct in your DB because:

1489377600 = Monday, 13-Mar-17 04:00:00 UTC in RFC 2822 but you have: "2017-03-13 00:00:00"

Please check one more time and confirm that you have SAME timezone on your capture server (kamailio sipcapture) and in your MySQL DB.

SELECT @@system_time_zone;

shaunbro commented 7 years ago

Thanks @adubovikov this is clearly the issue. We usually operate everything on UTC but in this case I was temporarily running the DB from a NAS device. Turns out the system time was not used by the database. I have modified and can now see new searches work correctly, historic searches always fail.

Is there no way to de-couple this reliance? Can I not just force UTC regardless of system time?

Thanks again.

adubovikov commented 7 years ago

you can use new version of db_mysql module. There we have fixed the issue.

adubovikov commented 7 years ago

so, looks like the issue has been fixed. I am closing the ticket....

adubovikov commented 7 years ago

https://github.com/sipcapture/homer/issues/207

adubovikov commented 7 years ago

I am reopening just be sure that everybody can fix it on their install

ishmaelen commented 7 years ago

Can I assume this is the same issue as described? The record exists, the search looks good but the results are 1 hour off.

Homer executes query: {"timestamp":{"from":1490192987319,"to":1490192987319},"param":{"search":{"id":1952,"callid":"9Wv7Sdz88gOUfsp4StALkg.."},"location":{"node":"single"},"transaction":{"call":true,"registration":false,"rest":false,"isup":false}}}

This shows a blank MSG and the response was:

{ "status": 200, "sid": "2q3628fi6b4hks82mtj6dm7qh3", "auth": "true", "message": "ok", "data": [ { "id": "1952", "date": "2017-03-22 14:29:47", "milli_ts": "1490192987319", "micro_ts": "1490192987319716", ....

$ date -d @1490192987.319 Wed 22 Mar 15:29:47 CET 2017

$ date +'%Z %z' CET +0100

MySQL date: "system_time_zone" "CET" "time_zone" "SYSTEM"

Generally I do not see this issue - but for some reasons it affects a few records.

I also see an error in the console but I have no idea if that is relevant or just saying no records were found so can't split the data..

angular.js:12520 TypeError: Cannot read property 'split' of null at swapText (dialogCtrl.js:54) at search.searchMethod.then.finally.$scope.dataLoading (dialogCtrl.js:81) at angular.js:14792 at r.$eval (angular.js:16052) at r.$digest (angular.js:15870) at r.$apply (angular.js:16160) at g (angular.js:10589) at T (angular.js:10787) at XMLHttpRequest.w.onload (angular.js:10728)

denzs commented 7 years ago

I have installed homer yesterday by the using the homer_installer.sh on Debian Jessie and i am facing (propably?!) the same issue... I updated Kamailio to 5.0 because of some Problems with HEPv3 from Freeswitch, but thats another story...

First i was irritated by # 012 sequences in the logged Query, but i think this is just some cosmetic issue of newlines while logging the query?!

However, when i execute the query from the log inside of mysql i get 100 rows as result...

But in the webui i dont get any result...

Is there any way to increase the logging or anything else i can do to help investigate this issue?

mysql timezones:

mysql> SELECT @@system_time_zone;
+--------------------+
| @@system_time_zone |
+--------------------+
| CEST               |
+--------------------+
1 row in set (0,00 sec)

mysql> SELECT @@time_zone;
+-------------+
| @@time_zone |
+-------------+
| SYSTEM      |
+-------------+
1 row in set (0,00 sec)

mysql> 

syslog:

Sep 14 16:52:49 siptrace homerlog[727]: Search query: SELECT id, date, (micro_ts DIV 1000) as milli_ts, micro_ts,method,reply_reason,ruri,ruri_user,ruri_domain,from_user,from_domain,from_tag,#012to_user,to_domain,to_tag,pid_user,contact_user,auth_user,callid,callid_aleg,via_1,via_1_branch,cseq,diversion,reason,content_type,auth,#012user_agent,source_ip,source_port,destination_ip,destination_port,contact_ip,contact_port,originator_ip,originator_port,correlation_id,proto,family,rtp_stat,type,node,'call' as trans,'single' as dbnode FROM sip_capture_call_20170913  WHERE (date BETWEEN FROM_UNIXTIME(1505253600) AND FROM_UNIXTIME(1505339999)) LIMIT 100

tcpdump:

POST /api/v1/search/data HTTP/1.1
Host: siptrace.intranet.customer.de
Connection: keep-alive
Content-Length: 290
Accept: application/json, text/plain, */*
Origin: http://siptrace.intranet.customer.de
User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/57.0.2987.133 Safari/537.36
Content-Type: application/json;charset=UTF-8
Referer: http://siptrace.intranet.customer.de/
Accept-Encoding: gzip, deflate
Accept-Language: de,en-US;q=0.8,en;q=0.6
Cookie: _ga=GA1.2.633622466.1407399103; HOMERSESSID=m9p76apb8qrkvai6thqp3v1th6

{"param":{"transaction":{"call":true,"registration":true,"rest":true},"limit":200,"search":{"limit":"10000","user_agent":""},"location":{"node":[{"id":"1","name":"node1"}]},"timezone":{"value":-120,"name":"GMT+2 EET","offset":"+0200"}},"timestamp":{"from":1505253600000,"to":1505339999099}}
16:48:31.292530 IP siptrace.intranet.customer.de.http > bart.ar.intranet.customer.de.43414: Flags [.], ack 863, win 240, options [nop,nop,TS val 430773 ecr 7468753], length 0
.......B:..D....E..4..@.@...
.B.
.Bl.P..1..{&.F............
.....q..
16:48:43.301818 IP siptrace.intranet.customer.de.http > bart.ar.intranet.customer.de.43414: Flags [P.], seq 1:323, ack 863, win 240, options [nop,nop,TS val 433775 ecr 7468753], length 322: HTTP: HTTP/1.0 500 Internal Server Error
.......B:..D....E..v..@.@..K
.B.
.Bl.P..1..{&.F............
...o.q..HTTP/1.0 500 Internal Server Error
Date: Thu, 14 Sep 2017 14:48:31 GMT
Server: Apache/2.4.10 (Debian)
Expires: Thu, 19 Nov 1981 08:52:00 GMT
Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0
Pragma: no-cache
Content-Length: 0
Connection: close
Content-Type: text/html; charset=UTF-8

packages:

[0][root@siptrace:~]# dpkg -l|grep -e mysql -e kamailio
ii  kamailio                          5.0.3+jessie                       amd64        very fast, dynamic and configurable SIP server
ii  kamailio-extra-modules:amd64      5.0.3+jessie                       amd64        Extra modules for the Kamailio SIP Server
ii  kamailio-geoip-modules:amd64      5.0.3+jessie                       amd64        The geoip module for the Kamailio SIP Server
ii  kamailio-mysql-modules:amd64      5.0.3+jessie                       amd64        MySQL database connectivity module for Kamailio
ii  kamailio-outbound-modules:amd64   5.0.3+jessie                       amd64        SIP Outbound module for the Kamailio SIP server
ii  kamailio-sctp-modules:amd64       5.0.3+jessie                       amd64        SCTP SIP transport module for the Kamailio SIP server
ii  kamailio-tls-modules:amd64        5.0.3+jessie                       amd64        TLS support for the Kamailio SIP server (authentication, transport)
ii  kamailio-utils-modules:amd64      5.0.3+jessie                       amd64        Utility functions for the Kamailio SIP server
ii  kamailio-websocket-modules:amd64  5.0.3+jessie                       amd64        WebSocket module for the Kamailio SIP server
ii  libclass-dbi-mysql-perl           1.00-3                             all          extensions to Class::DBI for MySQL
ii  libdbd-mysql-perl                 4.028-2+deb8u2                     amd64        Perl5 database interface to the MySQL database
ii  libmysqlclient18:amd64            5.5.57-0+deb8u1                    amd64        MySQL database client library
ii  mysql-client                      5.7.19-1debian8                    amd64        MySQL Client meta package depending on latest version
ii  mysql-common                      5.7.19-1debian8                    amd64        MySQL Common
ii  mysql-community-client            5.7.19-1debian8                    amd64        MySQL Client
ii  mysql-community-server            5.7.19-1debian8                    amd64        MySQL Server
ii  mysql-server                      5.7.19-1debian8                    amd64        MySQL Server meta package depending on latest version
ii  php5-mysql                        5.6.30+dfsg-0+deb8u1               amd64        MySQL module for php5
[0][root@siptrace:~]#