Completely reworked logging.

* Using slf4j and logback for logging.
* Disabled all logging output from kotlogram by default.
This commit is contained in:
Fabian Schlenz 2016-07-20 06:37:24 +02:00
parent a43b81ee91
commit 1481e5625e
7 changed files with 128 additions and 149 deletions

View File

@ -14,9 +14,13 @@ repositories {
}
dependencies {
compile 'com.github.badoualy:kotlogram:497e5dd62d9bcb341f584164b04b4b537ce9d295'
compile('com.github.badoualy:kotlogram:497e5dd62d9bcb341f584164b04b4b537ce9d295') {
exclude module: 'slf4j-simple'
}
compile 'org.xerial:sqlite-jdbc:3.8.11.2'
compile 'com.github.spullara.mustache.java:compiler:0.8.18'
compile 'org.slf4j:slf4j-api:1.7.21'
compile 'ch.qos.logback:logback-classic:1.1.7'
}
run {

View File

@ -31,13 +31,17 @@ import java.util.List;
import java.util.Scanner;
import java.util.Vector;
import org.slf4j.LoggerFactory;
import org.slf4j.Logger;
public class CommandLineController {
private static Logger logger = LoggerFactory.getLogger(CommandLineController.class);
private ApiStorage storage;
public TelegramApp app;
public UserManager user = null;
public CommandLineController() {
Log.debug("CommandLineController started. App version %s", Config.APP_APPVER);
logger.info("CommandLineController started. App version {}", Config.APP_APPVER);
System.out.println("Telegram_Backup version " + Config.APP_APPVER + ", Copyright (C) 2016 Fabian Schlenz");
System.out.println();
System.out.println("Telegram_Backup comes with ABSOLUTELY NO WARRANTY. This is free software, and you are");
@ -54,46 +58,41 @@ public class CommandLineController {
System.exit(0);
}
Log.debug("Target dir at startup: %s", Config.FILE_BASE);
logger.debug("Target dir at startup: {}", Config.FILE_BASE);
if (CommandLineOptions.val_target != null) {
Config.FILE_BASE = CommandLineOptions.val_target;
}
Log.debug("Target dir after options: %s", Config.FILE_BASE);
logger.debug("Target dir after options: {}", Config.FILE_BASE);
System.out.println("Base directory for files: " + Config.FILE_BASE);
if (CommandLineOptions.cmd_list_accounts) this.list_accounts();
Log.debug("Initializing TelegramApp");
logger.debug("Initializing TelegramApp");
if (CommandLineOptions.cmd_debug_telegram) {
System.setProperty(org.slf4j.impl.SimpleLogger.DEFAULT_LOG_LEVEL_KEY, "DEBUG");
//System.setProperty(org.slf4j.impl.SimpleLogger.DEFAULT_LOG_LEVEL_KEY, "DEBUG");
} else {
System.setProperty(org.slf4j.impl.SimpleLogger.DEFAULT_LOG_LEVEL_KEY, "ERROR");
//System.setProperty(org.slf4j.impl.SimpleLogger.DEFAULT_LOG_LEVEL_KEY, "ERROR");
}
app = new TelegramApp(Config.APP_ID, Config.APP_HASH, Config.APP_MODEL, Config.APP_SYSVER, Config.APP_APPVER, Config.APP_LANG);
Log.debug("Checking accounts");
Log.up();
logger.trace("Checking accounts");
String account = null;
Vector<String> accounts = Utils.getAccounts();
if (CommandLineOptions.cmd_login) {
Log.debug("Login requested, doing nothing.");
logger.debug("Login requested, doing nothing.");
// do nothing
} else if (CommandLineOptions.val_account!=null) {
Log.debug("Account requested: %s", CommandLineOptions.val_account);
Log.debug("Checking accounts for match.");
Log.up();
logger.debug("Account requested: {}", CommandLineOptions.val_account);
logger.trace("Checking accounts for match.");
boolean found = false;
for (String acc : accounts) {
Log.debug("Checking %s", acc);
Log.up();
logger.trace("Checking {}", acc);
if (acc.equals(CommandLineOptions.val_account)) {
found=true;
Log.debug("Matches.");
logger.trace("Matches.");
}
Log.down();
}
Log.down();
if (!found) {
show_error("Couldn't find account '" + CommandLineOptions.val_account + "'. Maybe you want to use '--login' first?");
}
@ -109,25 +108,23 @@ public class CommandLineController {
"Use '--account <x>' to use account <x>.\n" +
"Use '--list-accounts' to see all available accounts.");
}
Log.debug("accounts.size(): %d", accounts.size());
Log.debug("account: %s", account);
Log.debug("CommandLineOptions.cmd_login: %s", CommandLineOptions.cmd_login);
Log.down();
Log.debug("Initializing ApiStorage");
logger.debug("accounts.size(): {}", accounts.size());
logger.debug("account: {}", account);
logger.debug("CommandLineOptions.cmd_login: {}", CommandLineOptions.cmd_login);
logger.info("Initializing ApiStorage");
storage = new ApiStorage(account);
Log.debug("Initializing TelegramUpdateHandler");
logger.info("Initializing TelegramUpdateHandler");
TelegramUpdateHandler handler = new TelegramUpdateHandler();
Log.debug("Creating Client");
logger.info("Creating Client");
TelegramClient client = Kotlogram.getDefaultClient(app, storage, Kotlogram.PROD_DC4, handler);
try {
Log.debug("Creating UserManager");
logger.info("Creating UserManager");
user = new UserManager(client);
Log.debug("CommandLineOptions.val_export: %s", CommandLineOptions.val_export);
logger.debug("CommandLineOptions.val_export: {}", CommandLineOptions.val_export);
if (CommandLineOptions.val_export != null) {
Log.up();
if (CommandLineOptions.val_export.toLowerCase().equals("html")) {
(new HTMLExporter()).export(user);
System.exit(0);
@ -139,23 +136,20 @@ public class CommandLineController {
}
}
Log.debug("CommandLineOptions.cmd_login: %s", CommandLineOptions.cmd_login);
logger.debug("CommandLineOptions.cmd_login: {}", CommandLineOptions.cmd_login);
if (CommandLineOptions.cmd_login) {
Log.up();
cmd_login();
System.exit(0);
}
System.out.println("You are logged in as " + user.getUserString());
Log.debug("Initializing Download Manager");
Log.up();
logger.info("Initializing Download Manager");
DownloadManager d = new DownloadManager(user, client, new CommandLineDownloadProgress());
Log.debug("Calling DownloadManager.downloadMessages with limit %d", CommandLineOptions.val_limit_messages);
logger.debug("Calling DownloadManager.downloadMessages with limit {}", CommandLineOptions.val_limit_messages);
d.downloadMessages(CommandLineOptions.val_limit_messages);
Log.debug("Calling DownloadManager.downloadMedia");
logger.debug("Calling DownloadManager.downloadMedia");
d.downloadMedia();
Log.down();
} catch (Exception e) {
e.printStackTrace();
} finally {

View File

@ -17,10 +17,45 @@
package de.fabianonline.telegram_backup;
import de.fabianonline.telegram_backup.CommandLineController;
import org.slf4j.LoggerFactory;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.encoder.PatternLayoutEncoder;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.ConsoleAppender;
import ch.qos.logback.classic.Level;
public class CommandLineRunner {
public static void main(String[] args) {
CommandLineOptions.parseOptions(args);
// Set up logging
Logger logger = (Logger)LoggerFactory.getLogger(CommandLineRunner.class);
Logger rootLogger = (Logger)LoggerFactory.getLogger(org.slf4j.Logger.ROOT_LOGGER_NAME);
LoggerContext rootContext = rootLogger.getLoggerContext();
rootContext.reset();
PatternLayoutEncoder encoder = new PatternLayoutEncoder();
encoder.setContext(rootContext);
encoder.setPattern("%d{HH:mm:ss} %-5level %-35.-35(%logger{0}.%method): %message%n");
encoder.start();
ConsoleAppender<ILoggingEvent> appender = new ConsoleAppender<ILoggingEvent>();
appender.setContext(rootContext);
appender.setEncoder(encoder);
appender.start();
rootLogger.addAppender(appender);
rootLogger.setLevel(Level.OFF);
if (CommandLineOptions.cmd_debug) {
((Logger)LoggerFactory.getLogger("de.fabianonline.telegram_backup")).setLevel(Level.TRACE);
}
if (CommandLineOptions.cmd_debug_telegram) {
((Logger)LoggerFactory.getLogger("com.github.badoualy")).setLevel(Level.TRACE);
}
if (true || CommandLineOptions.cmd_console) {
// Always use the console for now.
new CommandLineController();

View File

@ -19,6 +19,8 @@ package de.fabianonline.telegram_backup;
import com.github.badoualy.telegram.tl.api.*;
import com.github.badoualy.telegram.tl.core.TLVector;
import com.github.badoualy.telegram.api.TelegramClient;
import org.slf4j.LoggerFactory;
import org.slf4j.Logger;
import java.sql.Connection;
import java.sql.DriverManager;
@ -49,6 +51,7 @@ public class Database {
private Statement stmt;
public UserManager user_manager;
public TelegramClient client;
private final static Logger logger = LoggerFactory.getLogger(Database.class);
public Database(UserManager user_manager, TelegramClient client) {
this(user_manager, client, true);
@ -91,7 +94,7 @@ public class Database {
try {
String src = user_manager.getFileBase() + Config.FILE_NAME_DB;
String dst = user_manager.getFileBase() + filename;
Log.debug("Copying %s to %s", src, dst);
logger.debug("Copying {} to {}", src, dst);
Files.copy(
new File(src).toPath(),
new File(dst).toPath(),

View File

@ -10,19 +10,21 @@ import java.sql.Types;
import java.sql.ResultSet;
import java.sql.PreparedStatement;
import com.github.badoualy.telegram.tl.api.*;
import org.slf4j.LoggerFactory;
import org.slf4j.Logger;
import de.fabianonline.telegram_backup.mediafilemanager.FileManagerFactory;
import de.fabianonline.telegram_backup.mediafilemanager.AbstractMediaFileManager;
public class DatabaseUpdates {
protected Connection conn;
protected Database db;
private static final Logger logger = LoggerFactory.getLogger(DatabaseUpdates.class);
private static LinkedList<DatabaseUpdate> updates = new LinkedList<DatabaseUpdate>();
public DatabaseUpdates(Connection conn, Database db) {
this.conn = conn;
this.db = db;
Log.debug("Registering Database Updates...");
Log.up();
logger.debug("Registering Database Updates...");
register(new DB_Update_1(conn, db));
register(new DB_Update_2(conn, db));
register(new DB_Update_3(conn, db));
@ -30,69 +32,58 @@ public class DatabaseUpdates {
register(new DB_Update_5(conn, db));
register(new DB_Update_6(conn, db));
register(new DB_Update_7(conn, db));
Log.down();
}
public void doUpdates() {
try {
Statement stmt = conn.createStatement();
ResultSet rs;
Log.debug("DatabaseUpdate.doUpdates running");
Log.up();
Log.debug("Getting current database version");
Log.up();
logger.debug("DatabaseUpdate.doUpdates running");
logger.debug("Getting current database version");
int version;
Log.debug("Checking if table database_versions exists");
logger.debug("Checking if table database_versions exists");
rs = stmt.executeQuery("SELECT COUNT(*) FROM sqlite_master WHERE type='table' AND name='database_versions'");
rs.next();
if (rs.getInt(1)==0) {
Log.debug("Table does not exist");
logger.debug("Table does not exist");
version = 0;
} else {
Log.debug("Table exists. Checking max version");
logger.debug("Table exists. Checking max version");
rs.close();
rs = stmt.executeQuery("SELECT MAX(version) FROM database_versions");
rs.next();
version = rs.getInt(1);
rs.close();
}
Log.debug("version: %d", version);
Log.down();
logger.debug("version: {}", version);
System.out.println("Database version: " + version);
Log.debug("Max available database version is %d", getMaxPossibleVersion());
logger.debug("Max available database version is {}", getMaxPossibleVersion());
if (version < getMaxPossibleVersion()) {
Log.debug("Update is necessary. %d => %d.", version, getMaxPossibleVersion());
logger.debug("Update is necessary. {} => {}.", version, getMaxPossibleVersion());
boolean backup = false;
for (int i=version+1; i<=getMaxPossibleVersion(); i++) {
if (getUpdateToVersion(i).needsBackup()) {
Log.debug("Update to version %d needs a backup", i);
logger.debug("Update to version {} needs a backup", i);
backup=true;
}
}
if (backup) {
Log.debug("Performing backup");
Log.up();
logger.debug("Performing backup");
db.backupDatabase(version);
Log.down();
}
Log.debug("Applying updates");
Log.up();
logger.debug("Applying updates");
try {
for (int i=version+1; i<=getMaxPossibleVersion(); i++) {
Log.up();
getUpdateToVersion(i).doUpdate();
Log.down();
}
} catch (SQLException e) { throw new RuntimeException(e); }
Log.down();
} else {
Log.debug("No update necessary.");
logger.debug("No update necessary.");
}
Log.down();
} catch (SQLException e) {
throw new RuntimeException(e);
}
@ -105,7 +96,7 @@ public class DatabaseUpdates {
}
private void register(DatabaseUpdate d) {
Log.debug("Registering %s as update to version %d", d.getClass().getName(), d.getVersion());
logger.debug("Registering {} as update to version {}", d.getClass().getName(), d.getVersion());
if (d.getVersion() != updates.size()+1) {
throw new RuntimeException("Tried to register DB update to version " + d.getVersion() + ", but would need update to version " + (updates.size()+1));
}
@ -117,6 +108,7 @@ abstract class DatabaseUpdate {
protected Connection conn;
protected Statement stmt;
protected Database db;
protected static final Logger logger = LoggerFactory.getLogger(DatabaseUpdate.class);
public DatabaseUpdate(Connection conn, Database db) {
this.conn = conn;
try {
@ -126,12 +118,10 @@ abstract class DatabaseUpdate {
}
public void doUpdate() throws SQLException {
Log.debug("Applying update to version %d", getVersion());
logger.debug("Applying update to version {}", getVersion());
System.out.println(" Updating to version " + getVersion() + "...");
Log.up();
_doUpdate();
Log.down();
Log.debug("Saving current database version to the db");
logger.debug("Saving current database version to the db");
stmt.executeUpdate("INSERT INTO database_versions (version) VALUES (" + getVersion() + ")");
}

View File

@ -33,6 +33,8 @@ import com.github.badoualy.telegram.tl.api.*;
import com.github.badoualy.telegram.tl.api.upload.TLFile;
import com.github.badoualy.telegram.tl.exception.RpcErrorException;
import com.github.badoualy.telegram.tl.api.request.TLRequestUploadGetFile;
import org.slf4j.LoggerFactory;
import org.slf4j.Logger;
import java.io.IOException;
import java.io.File;
@ -55,6 +57,7 @@ public class DownloadManager {
DownloadProgressInterface prog = null;
static TelegramClient download_client;
static boolean last_download_succeeded = true;
static final Logger logger = LoggerFactory.getLogger(DownloadManager.class);
public DownloadManager(UserManager u, TelegramClient c, DownloadProgressInterface p) {
this.user = u;
@ -88,11 +91,9 @@ public class DownloadManager {
}
public void _downloadMessages(Integer limit) throws RpcErrorException, IOException, TimeoutException {
Log.debug("This is _downloadMessages with limit %d", limit);
Log.up();
logger.info("This is _downloadMessages with limit {}", limit);
int dialog_limit = 100;
Log.debug("Downloading the last %d dialogs", dialog_limit);
Log.up();
logger.info("Downloading the last {} dialogs", dialog_limit);
System.out.println("Downloading most recent dialogs... ");
int max_message_id = 0;
TLAbsDialogs dialogs = client.messagesGetDialogs(
@ -100,15 +101,13 @@ public class DownloadManager {
0,
new TLInputPeerEmpty(),
dialog_limit);
Log.debug("Got %d dialogs", dialogs.getDialogs().size());
Log.up();
logger.debug("Got {} dialogs", dialogs.getDialogs().size());
for (TLDialog d : dialogs.getDialogs()) {
if (d.getTopMessage() > max_message_id) {
Log.debug("Updating top message id: %d => %d", max_message_id, d.getTopMessage());
logger.trace("Updating top message id: {} => {}", max_message_id, d.getTopMessage());
max_message_id = d.getTopMessage();
}
}
Log.down();
System.out.println("Top message ID is " + max_message_id);
int max_database_id = db.getTopMessageID();
System.out.println("Top message ID in database is " + max_database_id);
@ -117,8 +116,7 @@ public class DownloadManager {
max_database_id = Math.max(max_database_id, max_message_id-limit);
System.out.println("New top message id 'in database' is " + max_database_id);
}
Log.down();
if (max_database_id == max_message_id) {
System.out.println("No new messages to download.");
} else if (max_database_id > max_message_id) {
@ -131,14 +129,13 @@ public class DownloadManager {
downloadMessages(ids);
}
Log.debug("Searching for missing messages in the db");
Log.up();
logger.info("Searching for missing messages in the db");
int count_missing = 0;
System.out.println("Checking message database for completeness...");
int db_count = db.getMessageCount();
int db_max = db.getTopMessageID();
Log.debug("db_count: %d", db_count);
Log.debug("db_max: %d", db_max);
logger.debug("db_count: {}", db_count);
logger.debug("db_max: {}", db_max);
if (db_count != db_max) {
if (limit != null) {
@ -152,40 +149,35 @@ public class DownloadManager {
}
}
Log.debug("Logging this run");
logger.info("Logging this run");
db.logRun(Math.min(max_database_id + 1, max_message_id), max_message_id, count_missing);
Log.down();
}
private void downloadMessages(List<Integer> ids) throws RpcErrorException, IOException {
prog.onMessageDownloadStart(ids.size());
Log.debug("Entering download loop");
Log.up();
logger.debug("Entering download loop");
while (ids.size()>0) {
Log.debug("Loop");
Log.up();
logger.trace("Loop");
TLIntVector vector = new TLIntVector();
for (int i=0; i<100; i++) {
if (ids.size()==0) break;
vector.add(ids.remove(0));
}
Log.debug("vector.size(): %d", vector.size());
Log.debug("ids.size(): %d", ids.size());
logger.trace("vector.size(): {}", vector.size());
logger.trace("ids.size(): {}", ids.size());
TLAbsMessages response = client.messagesGetMessages(vector);
prog.onMessageDownloaded(response.getMessages().size());
db.saveMessages(response.getMessages(), Kotlogram.API_LAYER);
db.saveChats(response.getChats());
db.saveUsers(response.getUsers());
Log.debug("Sleeping");
logger.trace("Sleeping");
try {
Thread.sleep(Config.DELAY_AFTER_GET_MESSAGES);
} catch (InterruptedException e) {}
Log.down();
}
Log.down();
Log.debug("Finished.");
logger.debug("Finished.");
prog.onMessageDownloadFinished();
}
@ -205,7 +197,6 @@ public class DownloadManager {
throw e;
}
} catch (TimeoutException e) {
Log.down();
completed = false;
System.out.println("");
System.out.println("Telegram took too long to respond to our request.");
@ -217,39 +208,35 @@ public class DownloadManager {
}
private void _downloadMedia() throws RpcErrorException, IOException, TimeoutException {
Log.debug("This is _downloadMedia");
Log.debug("Checking if there are messages in the DB with a too old API layer");
logger.info("This is _downloadMedia");
logger.info("Checking if there are messages in the DB with a too old API layer");
LinkedList<Integer> ids = db.getIdsFromQuery("SELECT id FROM messages WHERE has_media=1 AND api_layer<" + Kotlogram.API_LAYER);
if (ids.size()>0) {
System.out.println("You have " + ids.size() + " messages in your db that need an update. Doing that now.");
Log.debug("Found %d messages", ids.size());
logger.debug("Found {} messages", ids.size());
downloadMessages(ids);
}
LinkedList<TLMessage> messages = this.db.getMessagesWithMedia();
Log.debug("Database returned %d messages with media", messages.size());
logger.debug("Database returned {} messages with media", messages.size());
prog.onMediaDownloadStart(messages.size());
Log.up();
for (TLMessage msg : messages) {
AbstractMediaFileManager m = FileManagerFactory.getFileManager(msg, user, client);
Log.debug("Message ID: %d Media type: %-10.10s FileManager type: %-10.10s isEmpty: %-5s isDownloaded: %-5s",
logger.trace("message {}, {}, {}, {}, {}",
msg.getId(),
msg.getMedia().getClass().getSimpleName().replace("TLMessageMedia", ""),
m.getClass().getSimpleName().replace("FileManager", ""),
m.isEmpty(),
m.isDownloaded());
m.getClass().getSimpleName(),
m.isEmpty() ? "empty" : "non-empty",
m.isDownloaded() ? "downloaded" : "not downloaded");
if (m.isEmpty()) {
prog.onMediaDownloadedEmpty();
} else if (m.isDownloaded()) {
prog.onMediaAlreadyPresent(m);
} else {
Log.up();
m.download();
Log.down();
prog.onMediaDownloaded(m);
}
}
Log.down();
prog.onMediaDownloadFinished();
}
@ -273,24 +260,24 @@ public class DownloadManager {
FileOutputStream fos = null;
try {
String temp_filename = target + ".downloading";
Log.debug("Temporary filename %s", temp_filename);
logger.debug("Temporary filename {}", temp_filename);
int offset = 0;
if (new File(temp_filename).isFile()) {
Log.debug("Temporary filename already exists; continuing this file");
logger.info("Temporary filename already exists; continuing this file");
offset = (int)new File(temp_filename).length();
if (offset >= size) {
Log.debug("Temporary file size is >= the target size. Assuming corrupt file & deleting it");
logger.warn("Temporary file size is >= the target size. Assuming corrupt file & deleting it");
new File(temp_filename).delete();
offset = 0;
}
}
Log.debug("offset before the loop is %d", offset);
logger.debug("offset before the loop is {}", offset);
fos = new FileOutputStream(temp_filename, true);
TLFile response;
do {
int block_size = size;
Log.debug("offset: %8d block_size: %7d size: %8d", offset, block_size, size);
logger.trace("offset: {} block_size: {} size: {}", offset, block_size, size);
TLRequestUploadGetFile req = new TLRequestUploadGetFile(loc, offset, block_size);
if (dcID==null) {
response = (TLFile) download_client.executeRpcQuery(req);
@ -299,7 +286,7 @@ public class DownloadManager {
}
offset += response.getBytes().getData().length;
Log.debug("response: %8d total size: %8d", response.getBytes().getData().length, offset);
logger.trace("response: {} total size: {}", response.getBytes().getData().length, offset);
fos.write(response.getBytes().getData());
fos.flush();
@ -311,7 +298,7 @@ public class DownloadManager {
new File(temp_filename).delete();
System.exit(1);
}
Log.debug("Renaming %s to %s", temp_filename, target);
logger.debug("Renaming {} to {}", temp_filename, target);
Files.move(new File(temp_filename).toPath(), new File(target).toPath(), StandardCopyOption.REPLACE_EXISTING);
last_download_succeeded = true;
return true;
@ -328,7 +315,7 @@ public class DownloadManager {
}
last_download_succeeded = false;
System.out.println("Got an Internal Server Error from Telegram. Skipping this file for now. Next run of telegram_backup will continue to download this file.");
Log.debug(ex.toString());
logger.warn(ex.toString());
return false;
}
System.out.println("RpcErrorException happened while downloading " + target);

View File

@ -1,34 +0,0 @@
/* Telegram_Backup
* Copyright (C) 2016 Fabian Schlenz
*
* This program is free software: you can redistribute it and/or modify
* it under the terms of the GNU General Public License as published by
* the Free Software Foundation, either version 3 of the License, or
* (at your option) any later version.
*
* This program is distributed in the hope that it will be useful,
* but WITHOUT ANY WARRANTY; without even the implied warranty of
* MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
* GNU General Public License for more details.
*
* You should have received a copy of the GNU General Public License
* along with this program. If not, see <http://www.gnu.org/licenses/>. */
package de.fabianonline.telegram_backup;
public class Log {
static int level = 0;
static final int factor = 2;
public static void up() { level++; }
public static void down() { level--; if (level<0) level=0; }
public static void debug(String s, Object... o) {
if (!CommandLineOptions.cmd_debug) return;
Object o2[] = new Object[o.length+1];
System.arraycopy(o, 0, o2, 0, o.length);
o2[o2.length-1]="";
String format = "DEBUG:" + '%' + o2.length + "$" + (level*factor+1) + "s" + s + "\n";
System.out.printf(format, o2);
}
}