Тестируем 5.3.002
обновился до U11, после запуска словил постоянно повторяющееся зависание админки, в топ-е:
в майн дебаге в это время:
FreeBSD 8.0-RELEASE-p2 #0
откатился на U9, отписал в хотлайн
Код: Выделить всё
58363 root 36 44 0 132M 98868K umtxn 0 1:39 2.10% utm5_core
Код: Выделить всё
Dec 05 09:59:10 ?Debug : 28d54040 DBConnectionPool: DBConnectioManager pool [Default]: connection is popped
Dec 05 09:59:10 ?Debug : 28d54040 PluginManagerImpl: Got RfwPlugin plugin for event EventSessionChanged/82
Dec 05 09:59:10 ?Debug : 2c551ec0 DBConnection_mysql: <0x28d93000> SQL query takes 0.000 sec
Dec 05 09:59:10 ?Debug : 2c551ec0 RADIUS_Module: RADIUS session ID 3451 belongs to UTM5 ID 51093890
Dec 05 09:59:10 ?Debug : 2c551ec0 DBConnectionPool: DBConnectionManager pool [Default]: connection is pushed back
Dec 05 09:59:10 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: timestamp 1417755550 slink_id 204612
Dec 05 09:59:10 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: slink_id 204612 tclass_id 10
Dec 05 09:59:10 ?Debug : 29196d80 TrafficAggregator: push_charge: slink_id 204612 charge 0.000000
Dec 05 09:59:10 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: timestamp 1417755550 slink_id 204612
Dec 05 09:59:10 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: slink_id 204612 tclass_id 20
------
------
Dec 05 10:00:06 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: timestamp 1417755606 slink_id 200202
Dec 05 10:00:06 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: slink_id 200202 tclass_id 20
Dec 05 10:00:06 ?Debug : 29196d80 TrafficAggregator: push_charge: slink_id 200202 charge 0.000000
Dec 05 10:00:09 ?Debug : 28d53b40 StreamConnection: Sending message ID 0x4004
Dec 05 10:00:09 ?Debug : 2c551c40 StreamConnection: Got message ID 0x3001
Dec 05 10:00:09 ?Debug : 2c551c40 RemoteFirewallManager: fw@127.0.0.1: ping reply
Dec 05 10:00:10 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: timestamp 1417755610 slink_id 197134
Dec 05 10:00:10 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: slink_id 197134 tclass_id 10
Dec 05 10:00:10 ?Debug : 29196d80 TrafficAggregator: push_charge: slink_id 197134 charge 0.000000
Dec 05 10:00:10 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: timestamp 1417755610 slink_id 197134
Dec 05 10:00:10 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: slink_id 197134 tclass_id 20
Dec 05 10:00:10 ?Debug : 29196d80 TrafficAggregator: push_charge: slink_id 197134 charge 0.000000
Dec 05 10:00:11 ERROR : 2cdb4100 DBConnection_mysql: <0x28d90800> MySQL query failed:<Unknown column 'is_deleted' in 'where clause'> Trying to reconnect: 1
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: timestamp 1417755611 slink_id 201280
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: slink_id 201280 tclass_id 10
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: push_charge: slink_id 201280 charge 0.000000
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: timestamp 1417755611 slink_id 201280
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: slink_id 201280 tclass_id 20
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: push_charge: slink_id 201280 charge 0.000000
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: timestamp 1417755611 slink_id 194107
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: slink_id 194107 tclass_id 20
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: push_charge: slink_id 194107 charge 0.000000
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: timestamp 1417755611 slink_id 202122
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: slink_id 202122 tclass_id 10
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: push_charge: slink_id 202122 charge 0.000000
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: timestamp 1417755611 slink_id 202122
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: slink_id 202122 tclass_id 20
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: push_charge: slink_id 202122 charge 0.000000
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: timestamp 1417755611 slink_id 204318
Dec 05 10:00:11 ?Debug : 29196d80 TrafficAggregator: charge_on_timeout: slink_id 204318 tclass_id 10
откатился на U9, отписал в хотлайн
Да накосячили разработчики:
Если сравнивать файлы UTM5_MYSQL_update.sql из сборки для freebsd 8 то различия только в строке "ALTER TABLE switch_types ADD COLUMN port_start_offset int DEFAULT '1' NOT NULL;", если для сборки freebsd 10 то различий вообще нет.
если обратить внимание на файлы UTM5_MYSQL.sql, то всплывает еще разница не отраженная в апдейтах:
INSERT INTO acts_templates(act_id,is_old,gen_date,act_name,doc_type,def,act_text) VALUES('28','0','0','Detail invoice','28','1','');
INSERT INTO template_type(type_id,type_name) VALUES('28','Detail invoice');
Если сравнивать файлы UTM5_MYSQL_update.sql из сборки для freebsd 8 то различия только в строке "ALTER TABLE switch_types ADD COLUMN port_start_offset int DEFAULT '1' NOT NULL;", если для сборки freebsd 10 то различий вообще нет.
если обратить внимание на файлы UTM5_MYSQL.sql, то всплывает еще разница не отраженная в апдейтах:
INSERT INTO acts_templates(act_id,is_old,gen_date,act_name,doc_type,def,act_text) VALUES('28','0','0','Detail invoice','28','1','');
INSERT INTO template_type(type_id,type_name) VALUES('28','Detail invoice');
Дык и не увидишь, я имею ввиду что разработчики забыли поправить файл.Point писал(а):не забыл,
1: вставлена строка 1506 правого файла (UTM5_MYSQL_update.sql U11) после строки 1505 левого файла (UTM5_MYSQL_update.sql U9)
ALTER TABLE switch_types ADD COLUMN port_start_offset int DEFAULT '1' NOT NULL;
больше изменений в структуре базы не вижу
Посмотри по дебагу на каком SQL спотыкается
Сейчас перевыложим сборки. Временное решение:
Код: Выделить всё
ALTER TABLE invoices ADD COLUMN is_deleted INT NOT NULL DEFAULT '0';
ALTER TABLE invoice_entry ADD COLUMN is_deleted INT NOT NULL DEFAULT '0';
ALTER TABLE invoice_entry_details ADD COLUMN is_deleted INT NOT NULL DEFAULT '0';
Помогло, заработалоserjk писал(а):Сейчас перевыложим сборки. Временное решение:
Код: Выделить всё
ALTER TABLE invoices ADD COLUMN is_deleted INT NOT NULL DEFAULT '0'; ALTER TABLE invoice_entry ADD COLUMN is_deleted INT NOT NULL DEFAULT '0'; ALTER TABLE invoice_entry_details ADD COLUMN is_deleted INT NOT NULL DEFAULT '0';
Я утром поставил на Debian 7.
Через некоторое время вот такое словил
Версия
Через некоторое время вот такое словил
Код: Выделить всё
Dec 5 08:34:30 UTM kernel: [1006366.560607] utm5_core[2997]: segfault at 0 ip 00000000009fb357 sp 00007fe53da1b6f0 error 4 in utm5_core[400000+9f6000]
Dec 5 15:05:00 UTM kernel: [1029796.130974] utm5_dhcpd[28852]: segfault at 18 ip 00000000004bb004 sp 00007fa30146ee68 error 4 in utm5_dhcpd[400000+384000]
Код: Выделить всё
NetUP UTM billing system core. Compile date: Dec 3 2014 10:50:16
Version:5.3-002-update11-debian_wheezy_x64 Rev #14502
Сыпется на update 11 - utm5_dhcp, пока через gdb не поймал.
Платформа
Код: Выделить всё
Dec 5 20:24:29 UTM kernel: [ 67.065635] utm5_dhcpd[2982]: segfault at 18 ip 00000000004bb004 sp 00007f6078a67e68 error 4 in utm5_dhcpd[400000+384000]
Dec 6 12:27:25 UTM kernel: [57842.787075] utm5_dhcpd[4570]: segfault at 18 ip 00000000004bb004 sp 00007f789ac0fe68 error 4 in utm5_dhcpd[400000+384000]
Dec 6 15:27:14 UTM kernel: [68631.765641] utm5_dhcpd[6412]: segfault at 18 ip 00000000004bb004 sp 00007fc955515e68 error 4 in utm5_dhcpd[400000+384000]
Dec 6 20:38:28 UTM kernel: [87305.323975] utm5_dhcpd[6915]: segfault at 18 ip 00000000004bb004 sp 00007f642d05de68 error 4 in utm5_dhcpd[400000+384000]
Код: Выделить всё
Debian 7.7
Linux UTM 3.14-0.bpo.1-amd64 #1 SMP Debian 3.14.12-1~bpo70+1 (2014-07-13) x86_64 GNU/Linux
Разработчикам
Поймал этот баг
Ядро последнее
В логе
Поймал этот баг
Код: Выделить всё
Starting program: /netup/utm5/bin/utm5_dhcpd
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7ffff7f5e700 (LWP 5401)]
[New Thread 0x7ffff40a0700 (LWP 5402)]
[Thread 0x7ffff40a0700 (LWP 5402) exited]
[New Thread 0x7ffff3693700 (LWP 5403)]
[New Thread 0x7ffff3592700 (LWP 5404)]
UTM5 DHCPD started (0 sec)
[New Thread 0x7ffff3491700 (LWP 5406)]
Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ffff3592700 (LWP 5404)]
0x00000000004bb004 in UTM::IP_address::operator==(UTM::IP_address const&) const ()
(gdb) thr a a bt full
Thread 6 (Thread 0x7ffff3491700 (LWP 5406)):
#0 0x00007ffff5f6cb73 in poll () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#1 0x00000000004bd8d4 in UTM::Poll::wait() ()
No symbol table info available.
#2 0x00000000004bdaa3 in UTM::Poll::wait(UTM::Socket const&) ()
No symbol table info available.
#3 0x0000000000435314 in UTM::StreamConnection::main() ()
No symbol table info available.
#4 0x00000000004a3e84 in UTM::StreamConnection::run() ()
No symbol table info available.
#5 0x00000000004ba174 in UTM::Thread::thread(void*) ()
No symbol table info available.
#6 0x00007ffff7367b50 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#7 0x00007ffff5f777bd in clone () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#8 0x0000000000000000 in ?? ()
No symbol table info available.
Thread 5 (Thread 0x7ffff3592700 (LWP 5404)):
#0 0x00000000004bb004 in UTM::IP_address::operator==(UTM::IP_address const&) const ()
No symbol table info available.
#1 0x00000000004627ba in DHCPD::Server::process_interface(DHCPD::Server::Interface*) ()
No symbol table info available.
#2 0x0000000000463861 in DHCPD::Server::run() ()
No symbol table info available.
#3 0x00000000004ba174 in UTM::Thread::thread(void*) ()
No symbol table info available.
#4 0x00007ffff7367b50 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#5 0x00007ffff5f777bd in clone () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#6 0x0000000000000000 in ?? ()
No symbol table info available.
Thread 4 (Thread 0x7ffff3693700 (LWP 5403)):
#0 0x00007ffff736c6bb in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#1 0x0000000000476f1c in DHCPD::Transport::run() ()
No symbol table info available.
#2 0x00000000004ba174 in UTM::Thread::thread(void*) ()
No symbol table info available.
#3 0x00007ffff7367b50 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#4 0x00007ffff5f777bd in clone () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#5 0x0000000000000000 in ?? ()
No symbol table info available.
Thread 2 (Thread 0x7ffff7f5e700 (LWP 5401)):
#0 0x00007ffff736c6bb in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#1 0x00000000004882e6 in UTM::LoggerImpl::run() ()
No symbol table info available.
#2 0x00000000004ba174 in UTM::Thread::thread(void*) ()
No symbol table info available.
#3 0x00007ffff7367b50 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
No symbol table info available.
#4 0x00007ffff5f777bd in clone () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
---Type <return> to continue, or q <return> to quit---
#5 0x0000000000000000 in ?? ()
No symbol table info available.
Thread 1 (Thread 0x7ffff7fe1740 (LWP 5398)):
#0 0x00007ffff5f472bd in nanosleep () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#1 0x00007ffff5f719d4 in usleep () from /lib/x86_64-linux-gnu/libc.so.6
No symbol table info available.
#2 0x0000000000434cca in main ()
No symbol table info available.
(gdb) bt
#0 0x00000000004bb004 in UTM::IP_address::operator==(UTM::IP_address const&) const ()
#1 0x00000000004627ba in DHCPD::Server::process_interface(DHCPD::Server::Interface*) ()
#2 0x0000000000463861 in DHCPD::Server::run() ()
#3 0x00000000004ba174 in UTM::Thread::thread(void*) ()
#4 0x00007ffff7367b50 in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#5 0x00007ffff5f777bd in clone () from /lib/x86_64-linux-gnu/libc.so.6
#6 0x0000000000000000 in ?? ()
Код: Выделить всё
Linux UTM 3.16.0-0.bpo.4-amd64 #1 SMP Debian 3.16.7-2~bpo70+1 (2014-12-01) x86_64 GNU/Linux
Код: Выделить всё
Dec 7 19:16:20 UTM kernel: [25797.990284] utm5_dhcpd[3043]: segfault at 18 ip 00000000004bb004 sp 00007fae3273de68 error 4 in utm5_dhcpd[400000+384000]
Для сравнения на update 9 utm5_dhcpd стабильно работает.
Дебаг
Код: Выделить всё
Dec 08 22:14:12 ERROR : 45632700 DHCP_Server: send_offer: BindingNotFoundError: no suitable binding
Dec 08 22:14:14 ERROR : 45632700 DHCP_Server: send_offer: BindingNotFoundError: no suitable binding
Dec 08 22:14:14 ERROR : 45632700 DHCP_Server: send_offer: BindingNotFoundError: no suitable binding
Dec 08 22:14:17 ERROR : 45632700 PoolManager: IP 172.20.27.29 from unknown pool
Dec 08 22:14:17 ERROR : 45632700 DHCP_Server: PoolManagerError: no such pool
Dec 08 22:14:18 ERROR : 45632700 PoolManager: IP 172.20.32.8 from unknown pool
Dec 08 22:14:18 ERROR : 45632700 DHCP_Server: PoolManagerError: no such pool
Dec 08 22:14:25 ERROR : 45632700 PoolManager: IP 172.20.19.11 from unknown pool
Dec 08 22:14:25 ERROR : 45632700 DHCP_Server: PoolManagerError: no such pool
Segmentation fault
Код: Выделить всё
Dec 08 22:14:25 ?Debug : 45632700 DBConnection_mysql: <0x13c3370> SQL SELECT query: SELECT id,ip,expired,client_id,binding_id,flags FROM dhcp_leases WHERE mac='00:25:22:3b:7c:42' ORDER BY id
Dec 08 22:14:25 ?Debug : 45632700 DBConnection_mysql: <0x13c3370> SQL SELECT query: 0 rows in 0.001 sec
Dec 08 22:14:25 ?Debug : 45632700 LeaseManager: no lease for MAC 00:25:22:3b:7c:42 found
Dec 08 22:14:25 ?Debug : 45632700 DHCP_Server: got DHCPINFORM packet
Dec 08 22:14:25 ?Debug : 45632700 DHCP_Server: sending ACK to 00:25:22:3b:7c:42
Dec 08 22:14:25 ERROR : 45632700 PoolManager: IP 172.20.19.11 from unknown pool
Dec 08 22:14:25 ERROR : 45632700 DHCP_Server: PoolManagerError: no such pool