Time Sync Issue --> db_time is null

[Cyberwolf2]

Arrr ...

This is happening now, db_time is not updating and I can't find the perl file that is responsible for updating it. What is responsible for updating for this?

INB4 - I'm using Asterisk 18.18.1, it is set in correctly in the server table as well astguiclient.conf file. It's using AMI2 since Asterisk version is >= 13

Checking db and server time:

Code: Select all

MariaDB [asterisk]> select * from server_updater;
+---------------+---------------------+---------+
| server_ip     | last_update         | db_time |
+---------------+---------------------+---------+
| 192.168.1.125 | 2024-10-03 15:49:46 | NULL    |
+---------------+---------------------+---------+
1 row in set (0.000 sec)


scripts using db_time:

Code: Select all

root@dialer:/usr/share/astguiclient# grep -Rnw '.' -e 'db_time'
./MySQL_AST_CREATE_tables.sql:260:db_time TIMESTAMP,
./MySQL_AST_CREATE_tables.sql:3795:db_time DATETIME NOT NULL,
./MySQL_AST_CREATE_tables.sql:3803:KEY ajax_dbtime_key (db_time)
./MySQL_AST_CREATE_tables.sql:3809:db_time DATETIME NOT NULL,
./MySQL_AST_CREATE_tables.sql:3817:KEY ajax_dbtime_key (db_time)
./MySQL_AST_CREATE_tables.sql:3984:db_time DATETIME NOT NULL,
./MySQL_AST_CREATE_tables.sql:3991:KEY vdad_dbtime_key (db_time)
./MySQL_AST_CREATE_tables.sql:4701:db_time DATETIME NOT NULL,
./MySQL_AST_CREATE_tables.sql:4708:index (db_time),
./MySQL_AST_CREATE_tables.sql:4732:db_time DATETIME NOT NULL,
./MySQL_AST_CREATE_tables.sql:4744:index (db_time)
./ADMIN_cold_storage_log_tables.pl:1879:   $stmtA = "SELECT count(*) from vicidial_agent_visibility_log_archive WHERE db_time < '$del_time';";
./ADMIN_cold_storage_log_tables.pl:1948:         $stmtA = "SELECT * FROM vicidial_agent_visibility_log_archive WHERE db_time < '$del_time';";
./ADMIN_cold_storage_log_tables.pl:2018:            $stmtA = "DELETE FROM vicidial_agent_visibility_log_archive WHERE db_time < '$del_time';";
./AST_timecheck.pl:211:$stmtA = "SELECT su.server_ip,last_update,UNIX_TIMESTAMP(last_update),server_description,UNIX_TIMESTAMP(db_time),server_id,active FROM server_updater su,servers s where s.server_ip=su.server_ip;";
./ADMIN_archive_log_tables.pl:1034:            $stmtA = "DELETE FROM vicidial_agent_visibility_log_archive WHERE db_time < '$del_time';";
./ADMIN_archive_log_tables.pl:3450:         {$stmtA = "DELETE FROM vicidial_agent_visibility_log WHERE db_time < '$del_time';";}
./ADMIN_keepalive_ALL.pl:2081:      $stmtA = "DELETE from vicidial_ajax_log where db_time < \"$SDSQLdate\";";
./ADMIN_keepalive_ALL.pl:2099:      $stmtA = "DELETE from vicidial_sync_log where db_time < \"$SDSQLdate\";";
./ADMIN_keepalive_ALL.pl:2117:      $stmtA = "DELETE from vicidial_vdad_log where db_time < \"$SDSQLdate\";";
./ADMIN_keepalive_ALL.pl:2207:      $stmtA = "DELETE from vicidial_tiltx_shaken_log where db_time < \"$SDSQLdate\";";


screen -ls

Code: Select all

root@dialer:/usr/share/astguiclient# screen -ls
There are screens on:
   95565.ASTupdate   (10/03/2024 03:37:03 PM)   (Detached)
   2004.ASTlisten   (10/03/2024 06:33:03 AM)   (Detached)
   2009.ASTVDauto   (10/03/2024 06:33:03 AM)   (Detached)
   2014.ASTVDremote   (10/03/2024 06:33:03 AM)   (Detached)
   2019.ASTVDadapt   (10/03/2024 06:33:03 AM)   (Detached)
   2024.ASTfastlog   (10/03/2024 06:33:03 AM)   (Detached)
   1999.ASTsend   (10/03/2024 06:33:02 AM)   (Detached)
   1805.asterisk   (10/03/2024 06:32:25 AM)   (Detached)
   1798.astshell20241003063222   (10/03/2024 06:32:23 AM)   (Detached)
9 Sockets in /run/screen/S-root.


AST_timecheck.pl --debugXXX

Code: Select all

root@dialer:/usr/share/astguiclient# perl AST_timecheck.pl --debugXXX

----- DEBUG MODE -----


----- SUPER DEBUG MODE -----

Start time: 2024-10-03 15:58:46(1727985526)   TIME SYNC SECONDS: 10
   2|SELECT su.server_ip,last_update,UNIX_TIMESTAMP(last_update),server_description,UNIX_TIMESTAMP(db_time),server_id,active FROM server_updater su,servers s where s.server_ip=su.server_ip;|
Server time: 0 - 192.168.1.125(TESTast - Test install of Asterisk server)   Last time: 2024-10-03 15:58:46(1727985536|1727985526)


AST_update_AMI2.pl --debugXXX

Code: Select all

root@dialer:/usr/share/astguiclient# perl /usr/share/astguiclient/AST_update_AMI2.pl --debugXXX

----- DEBUGGING ENABLED -----


----- SUPER-DUPER DEBUGGING -----


|1|SELECT count(*) FROM server_updater where server_ip='192.168.1.125';|

|1|SHOW TABLES LIKE "cid_channels_recent_192168001125";|
1|cid_channels_recent_192168001125|SHOW TABLES LIKE "cid_channels_recent_192168001125";
----- AMI Version 7.0.3 -----


2024-10-03 16:00:01
|Channel List:
|total_channels|0
0 channels recieved out of 0 reported.|0|
|SELECT extension, protocol FROM phones where server_ip='192.168.1.125' and phone_type NOT LIKE "%trunk%"|
callin|EXTERNAL
gs102|SIP

UPDATE server_updater set last_update='2024-10-03 16:00:01' where server_ip='192.168.1.125'
BG_check_stats [0|0:0   0|0:0   0|0:0   0|0:0   0|0:0]
|no client channels to insert|
|no trunk channels to insert|
|no client channels to delete|
|no trunk channels to delete|
Park Dup Del|DELETE pc1 FROM parked_channels pc1, parked_channels pc2 WHERE pc1.parked_time < pc2.parked_time AND pc1.parked_time <> pc2.parked_time AND pc1.channel = pc2.channel AND pc1.server_ip='192.168.1.125' and pc2.server_ip='192.168.1.125'|0E0

Server Stats Updated|UPDATE servers SET sysload='012', channels_total='0', cpu_idle_percent='92', disk_usage='1 1|2 5|3 0|4 0|5 1|6 2|7 1|8 1|' where server_ip='192.168.1.125';|1
loop took 8488 microseconds. sleeping for 391512 microseconds to compensate



On admin.php --> Reports

Code: Select all

SERVER -   DESCRIPTION   IP   ACT   LOAD   CHAN   AGNT   DISK   TIME   VER
ViCi   ViCi   192.168.1.125   Y / Y / Y   193 - 21%   0   0   4%   2024-10-03 21:18:07   0
    PHP Time       2024-10-03 21:18:07   
    DB Time       2024-10-03 21:18:07   



It's showing all green on the web interface. All times sync.

ulimit:

Code: Select all

root@dialer:~# cat /proc/sys/fs/file-max
9223372036854775807
root@dialer:~# ulimit -Hn
1048576
root@dialer:~# ulimit -Sn
1024


My intuition tells me database misconfig. What do you think?

[Cyberwolf2]

Here is my bandaid. No one but my install needs this. There is probably a better and correct solution. I promise this for my reference.

I made a script that updates it every second and uses a lock file. Output of --debug can be redirected to file or console. This is meant to be activated via crontab.

CPAN dependencies:

DBI
Getopt::Long
Fcntl
Time::HiRes

Code: Select all

nano /usr/share/astguiclient/updatedb.pl

Code: Select all

#!/usr/bin/perl

use strict;
use warnings;
use DBI;
use Getopt::Long;
use POSIX ":sys_wait_h";
use Fcntl qw(:flock);
use Time::HiRes qw(sleep);

# Configuration
my $lock_file = "/tmp/update_db_time.lock"; # Path to the lock file
my $socket_file = "/var/run/mysqld/mysqld.sock"; # Replace with the actual path to your .sock file
my $database = "asterisk";              # Replace with your database name
my $username = "cron";              # Replace with your MySQL username
my $password = "1234";              # Replace with your MySQL password

# Command line options
my $debug = 0;  # Debug mode flag
my $help = 0;   # Help flag

# Parse command line options
GetOptions(
    "debug" => \$debug,
    "help"  => \$help,
) or die "Invalid options passed. Use --help for usage.\n";

# Display help message if --help is passed
if ($help) {
    print "Usage: $0 [options]\n";
    print "Options:\n";
    print "  --debug    Enable debug mode for verbose output\n";
    print "  --help     Display this help message\n";
    exit 0;
}

# Check if another instance is running
sub check_lock {
    open my $fh, ">", $lock_file or die "Can't open $lock_file: $!";
    if (!flock($fh, LOCK_EX | LOCK_NB)) {
        die "Another instance of the script is already running.\n";
    }
    # Write the process ID into the lock file
    print $fh $$;
    return $fh;
}

# Remove lock file on exit
sub remove_lock {
    unlink $lock_file or warn "Could not remove lock file: $!";
}

# Main logic to update db_time
sub update_db_time {
    while (1) {
        # Connect to the MySQL database using the Unix socket
        my $dsn = "DBI:mysql:database=$database;mysql_socket=$socket_file";
        my $dbh = DBI->connect($dsn, $username, $password, { RaiseError => 1, PrintError => 0 });

        if ($dbh) {
            if ($debug) {
                print "Connected to the database using Unix socket...\n";
            }

            # SQL query to update db_time
            my $sql = "UPDATE server_updater SET db_time = NOW()";
            if ($debug) {
                print "SQL Query: $sql\n";
            }

            # Execute the query
            my $sth = $dbh->prepare($sql);
            $sth->execute();

            if ($debug) {
                print "db_time updated successfully\n";
            }

            # Clean up database handles
            $sth->finish();
            $dbh->disconnect();

            if ($debug) {
                print "MySQL connection closed\n";
            }
        } else {
            warn "Error connecting to the database: $DBI::errstr\n";
        }

        # Sleep for 0.5 seconds before the next update
        sleep(0.5);
    }
}

# Main script execution
my $lock_fh = check_lock();
if ($debug) {
    print "Starting script with debug mode enabled...\n";
}

# Trap signals to ensure lock file is removed on exit
$SIG{INT} = $SIG{TERM} = sub {
    remove_lock();
    exit 0;
};

# Run the update_db_time loop
eval {
    update_db_time();
};

# If any error occurs, remove lock file and exit
if ($@) {
    warn "An error occurred: $@\n";
    remove_lock();
}

# Ensure lock is removed when the script exits normally
END {
    remove_lock();
}


Add it to crontab:

Code: Select all

crontab -e


Code: Select all

* * * * * /usr/share/astguiclient/updatedb.pl


[williamconley]

No script. Auto-updates:

Code: Select all

+-------------+-------------+------+-----+---------------------+-------------------------------+
| Field       | Type        | Null | Key | Default             | Extra                         |
+-------------+-------------+------+-----+---------------------+-------------------------------+
| server_ip   | varchar(15) | NO   | PRI | NULL                |                               |
| last_update | datetime    | YES  |     | NULL                |                               |
| db_time     | timestamp   | NO   |     | current_timestamp() | on update current_timestamp() |
+-------------+-------------+------+-----+---------------------+-------------------------------+


[Cyberwolf2]

Thanks, this is exactly what it was.... updated table structure. Fixed

I wonder why this happened. So I doublechecked my.cnf and double checked chris's install scripts. I had sql_mode=" " when I originally made this database. I had multiple little bugs, I believe all were squashed after updating sql_mode"sql_mode="NO_ENGINE_SUBSTITUTION" and refreshing the database.

[williamconley]

When I bump into this sort of thing, it's usually because the tech deleted all those "comment lines" in a mysqldump. Which is fine for pure data loading, but not for table creation. Happens.

Of course, I would never ...

LOL: Hope it helped.