[freeswitch-users] mod_cdr_csv - rotate on hup is not working reliable
Hi, I am using cron job which executes: killall -HUP freeswitch Usually new cdr file is created every one minute: 2011-01-17 16:55:01.583043 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 16:56:01.861371 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 16:57:44.338974 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv Today I got some problems with network DB connection, as this also can be seen by few lines (I am using xml_curl to serve registrations): 2011-01-17 16:59:04.382035 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:24.443196 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:30.997069 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:30.997069 [WARNING] sofia_reg.c:2171 Can't find user [1000@xxx] You must define a domain called 'xxx' in your directory and add a user with the id="1000" attribute and you must configure your device to use the proper domain in it's authentication credentials. ... And I did not get any CDR file between 16:57 and 17:01. CDR rotation was restored after 4 minutes - 17:01 - BUT 3 times in 1 second! 2011-01-17 17:01:*44*.540795 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:01:*44*.540795 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:01:*44*.542071 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv The same repeated again in few minutes: 2011-01-17 17:05:*09*.701507 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:*09*.701507 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:*09*.853446 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:*14*.949815 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:*14*.952841 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv Because of this, I lost few call records (it is confirmed). File at 17:05:*14*.949815 (which contained 1 call record - as per logs) was overwritten by empty file at 17:05:*14*.952841. Basically my question is - is it expected behavior that such [rarely expected] errors make it behave this way? It is Freeswitch 1.0.7 on Ubuntu Server 10.4. Thank you, Vitalie
Do you have any information about what was happening during that four-minute period? I would have to wonder if there was something goofy happening with disk i/o or some other weirdness. The hard part is going to be reproducing it. If you are able to reproduce the symptoms then getting a gcore while the system is in the weird state might be useful for debugging purposes. What kind of load is on this system? Also, what are the system specs? -MC On Mon, Jan 17, 2011 at 1:48 PM, Vitalii Colosov <vetali100@gmail.com>wrote:
Hi,
I am using cron job which executes: killall -HUP freeswitch
Usually new cdr file is created every one minute:
2011-01-17 16:55:01.583043 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 16:56:01.861371 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 16:57:44.338974 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv
Today I got some problems with network DB connection, as this also can be seen by few lines (I am using xml_curl to serve registrations):
2011-01-17 16:59:04.382035 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:24.443196 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:30.997069 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:30.997069 [WARNING] sofia_reg.c:2171 Can't find user [1000@xxx] You must define a domain called 'xxx' in your directory and add a user with the id="1000" attribute and you must configure your device to use the proper domain in it's authentication credentials. ...
And I did not get any CDR file between 16:57 and 17:01.
CDR rotation was restored after 4 minutes - 17:01 - BUT 3 times in 1 second!
2011-01-17 17:01:*44*.540795 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:01:*44*.540795 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:01:*44*.542071 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv
The same repeated again in few minutes:
2011-01-17 17:05:*09*.701507 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:*09*.701507 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:*09*.853446 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv
2011-01-17 17:05:*14*.949815 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:*14*.952841 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv
Because of this, I lost few call records (it is confirmed).
File at 17:05:*14*.949815 (which contained 1 call record - as per logs) was overwritten by empty file at 17:05:*14*.952841.
Basically my question is - is it expected behavior that such [rarely expected] errors make it behave this way?
It is Freeswitch 1.0.7 on Ubuntu Server 10.4.
Thank you, Vitalie
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
you probably did not have your timeout set on the xml_curl or are you using odbc as well? when networks time out during odbc you were probably blocking the whole FS waiting for it to return. It's best not to rely on public networks for critical data. On Mon, Jan 17, 2011 at 6:10 PM, Michael Collins <msc@freeswitch.org> wrote:
Do you have any information about what was happening during that four-minute period? I would have to wonder if there was something goofy happening with disk i/o or some other weirdness. The hard part is going to be reproducing it. If you are able to reproduce the symptoms then getting a gcore while the system is in the weird state might be useful for debugging purposes. What kind of load is on this system? Also, what are the system specs? -MC
On Mon, Jan 17, 2011 at 1:48 PM, Vitalii Colosov <vetali100@gmail.com> wrote:
Hi, I am using cron job which executes: killall -HUP freeswitch Usually new cdr file is created every one minute: 2011-01-17 16:55:01.583043 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 16:56:01.861371 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 16:57:44.338974 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv
Today I got some problems with network DB connection, as this also can be seen by few lines (I am using xml_curl to serve registrations):
2011-01-17 16:59:04.382035 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:24.443196 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:30.997069 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:30.997069 [WARNING] sofia_reg.c:2171 Can't find user [1000@xxx] You must define a domain called 'xxx' in your directory and add a user with the id="1000" attribute and you must configure your device to use the proper domain in it's authentication credentials. ... And I did not get any CDR file between 16:57 and 17:01.
CDR rotation was restored after 4 minutes - 17:01 - BUT 3 times in 1 second! 2011-01-17 17:01:44.540795 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:01:44.540795 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:01:44.542071 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv
The same repeated again in few minutes: 2011-01-17 17:05:09.701507 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:09.701507 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:09.853446 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:14.949815 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:14.952841 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv
Because of this, I lost few call records (it is confirmed). File at 17:05:14.949815 (which contained 1 call record - as per logs) was overwritten by empty file at 17:05:14.952841.
Basically my question is - is it expected behavior that such [rarely expected] errors make it behave this way?
It is Freeswitch 1.0.7 on Ubuntu Server 10.4. Thank you, Vitalie
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ Twitter: http://twitter.com/FreeSWITCH_wire AIM: anthm MSN:anthony_minessale@hotmail.com GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com IRC: irc.freenode.net #freeswitch FreeSWITCH Developer Conference sip:888@conference.freeswitch.org googletalk:conf+888@conference.freeswitch.org pstn:+19193869900
Thank you Anthony. You are right twice. I don't have timeout in xml_curl configuration. And I am using core odbc as well. So probably whole FS was blocked because of short network outage. Just FYI, this is what I have in log between 16:57 and 17:01 - but I don't think it will add more light to this problem: 2011-01-17 16:57:44.338974 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 16:59:04.382035 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 16:59:10.739780 [WARNING] sofia_reg.c:1241 SIP auth challenge (REGISTER) on sofia profile 'internal' for [1000@my.domain.com] from ip *some_ip* 2011-01-17 17:00:24.443196 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:30.997069 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:30.997069 [WARNING] sofia_reg.c:2171 Can't find user [ 1000@my.domain.com] You must define a domain called 'my.domain.com' in your directory and add a user with the id="1000" attribute and you must configure your device to use the proper domain in it's authentication credentials. 2011-01-17 17:00:31.158235 [WARNING] sofia_reg.c:1199 SIP auth failure (REGISTER) on sofia profile 'internal' for [1000@my.domain.com] from ip *some_ip* 2011-01-17 17:00:51.394967 [WARNING] sofia_reg.c:1241 SIP auth challenge (REGISTER) on sofia profile 'internal' for [1000@my.domain.com] from ip *some_ip* 2011-01-17 17:01:44.539778 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:01:44.540795 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:01:44.540795 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:01:44.542071 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv I will optimize my configuration. Thank you, Vitalie 2011/1/18 Anthony Minessale <anthony.minessale@gmail.com>
you probably did not have your timeout set on the xml_curl or are you using odbc as well? when networks time out during odbc you were probably blocking the whole FS waiting for it to return. It's best not to rely on public networks for critical data.
On Mon, Jan 17, 2011 at 6:10 PM, Michael Collins <msc@freeswitch.org> wrote:
Do you have any information about what was happening during that four-minute period? I would have to wonder if there was something goofy happening with disk i/o or some other weirdness. The hard part is going to be reproducing it. If you are able to reproduce the symptoms then getting a gcore while the system is in the weird state might be useful for debugging purposes. What kind of load is on this system? Also, what are the system specs? -MC
On Mon, Jan 17, 2011 at 1:48 PM, Vitalii Colosov <vetali100@gmail.com> wrote:
Hi, I am using cron job which executes: killall -HUP freeswitch Usually new cdr file is created every one minute: 2011-01-17 16:55:01.583043 [NOTICE] mod_cdr_csv.c:123 Rotated CDR
logfile
/usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 16:56:01.861371 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 16:57:44.338974 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv
Today I got some problems with network DB connection, as this also can be seen by few lines (I am using xml_curl to serve registrations):
2011-01-17 16:59:04.382035 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:24.443196 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:30.997069 [ERR] switch_xml.c:1621 Error[[error near line 1]: root tag missing] 2011-01-17 17:00:30.997069 [WARNING] sofia_reg.c:2171 Can't find user [1000@xxx] You must define a domain called 'xxx' in your directory and add a user with the id="1000" attribute and you must configure your device to use the proper domain in it's authentication credentials. ... And I did not get any CDR file between 16:57 and 17:01.
CDR rotation was restored after 4 minutes - 17:01 - BUT 3 times in 1 second! 2011-01-17 17:01:44.540795 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:01:44.540795 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:01:44.542071 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv
The same repeated again in few minutes: 2011-01-17 17:05:09.701507 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:09.701507 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:09.853446 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:14.949815 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv 2011-01-17 17:05:14.952841 [NOTICE] mod_cdr_csv.c:123 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv
Because of this, I lost few call records (it is confirmed). File at 17:05:14.949815 (which contained 1 call record - as per logs) was overwritten by empty file at 17:05:14.952841.
Basically my question is - is it expected behavior that such [rarely expected] errors make it behave this way?
It is Freeswitch 1.0.7 on Ubuntu Server 10.4. Thank you, Vitalie
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE: http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
-- Anthony Minessale II
FreeSWITCH http://www.freeswitch.org/ ClueCon http://www.cluecon.com/ Twitter: http://twitter.com/FreeSWITCH_wire
AIM: anthm MSN:anthony_minessale@hotmail.com <MSN%3Aanthony_minessale@hotmail.com> GTALK/JABBER/PAYPAL:anthony.minessale@gmail.com<PAYPAL%3Aanthony.minessale@gmail.com> IRC: irc.freenode.net #freeswitch
FreeSWITCH Developer Conference sip:888@conference.freeswitch.org <sip%3A888@conference.freeswitch.org> googletalk:conf+888@conference.freeswitch.org<googletalk%3Aconf%2B888@conference.freeswitch.org> pstn:+19193869900
_______________________________________________ FreeSWITCH-users mailing list FreeSWITCH-users@lists.freeswitch.org http://lists.freeswitch.org/mailman/listinfo/freeswitch-users UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users http://www.freeswitch.org
participants (3)
-
Anthony Minessale
-
Michael Collins
-
Vitalii Colosov