Commit 4a6391e5 authored by zeroleak's avatar zeroleak
Browse files

clean logs

parent c5ace105
......@@ -7,7 +7,14 @@ Whirlpool server
cd whirlpool-server
cp src/main/resources/application.properties ./custom.properties
```
Settings from custom.properties will override default settings (src/main/resources/application.properties)
custom.properties will override default settings (src/main/resources/application.properties)
The following settings *NEED* to be overriden:
```
server.rpc-client.host = CONFIGURE-ME
server.rpc-client.user = CONFIGURE-ME
server.rpc-client.password = CONFIGURE-ME
```
- run from commandline:
```
......
package com.samourai.whirlpool.server;
import com.samourai.whirlpool.server.utils.LogbackUtils;
import org.apache.log4j.Level;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.ApplicationArguments;
import org.springframework.boot.ApplicationRunner;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
@SpringBootApplication
public class Application {
public class Application implements ApplicationRunner {
private static final Logger log = LoggerFactory.getLogger(Application.class);
private ApplicationArguments args;
public static void main(String[] args) {
SpringApplication.run(Application.class, args);
}
@Override
public void run(ApplicationArguments args) {
this.args = args;
if (args.containsOption("debug")) {
// enable debug logs
LogbackUtils.setLogLevel("com.samourai.whirlpool.server", Level.DEBUG.toString());
}
log.info("------------ whirlpool-server ------------");
}
}
......@@ -40,4 +40,8 @@ public class LiquidityPool {
public boolean hasLiquidity() {
return !liquiditiesById.isEmpty();
}
public int getNbLiquidities() {
return liquiditiesById.size();
}
}
......@@ -110,6 +110,14 @@ public class Round {
return inputsById.size();
}
public int getNbInputsMustMix() {
return (int)getInputs().parallelStream().filter(input -> !input.isLiquidity()).count();
}
public int getNbInputsLiquidities() {
return (int)getInputs().parallelStream().filter(input -> input.isLiquidity()).count();
}
public synchronized void registerInput(RegisteredInput registeredInput) throws RoundException {
String inputId = Utils.computeInputId(registeredInput.getInput());
if (inputsById.containsKey(inputId)) {
......
......@@ -37,17 +37,15 @@ public class RoundLimitsWatcher implements Runnable {
// timer expired => notify
roundLimitsManager.onRoundWatcherTimeout(round, this);
}
if (running) {
// sleep until next adjustment
timeToWait = roundLimitsManager.computeRoundWatcherTimeToWait(waitSince, round);
log.info(timeToWait+"ms to wait before next check.");
else {
if (log.isDebugEnabled()) {
log.debug(timeToWait + "ms to wait before next check.");
}
try {
Thread.sleep(timeToWait);
}
catch(InterruptedException e) {
log.error("", e);
// normal
}
}
}
......
......@@ -31,4 +31,8 @@ public class TxOutPoint {
}
return super.equals(obj);
}
public String toString() {
return hash+"-"+index+" ("+value+"sats)";
}
}
......@@ -71,16 +71,22 @@ public class WebsocketConfig extends AbstractWebSocketMessageBrokerConfigurer {
@EventListener
public void handleSubscribeEvent(SessionSubscribeEvent event) {
log.info("<==> handleSubscribeEvent: username="+event.getUser().getName()+", event="+event);
if (log.isDebugEnabled()) {
log.debug("[event] subscribe: username="+event.getUser().getName()+", event="+event);
}
}
@EventListener
public void handleConnectEvent(SessionConnectEvent event) {
log.info("===> handleConnectEvent: username="+event.getUser().getName()+", event="+event);
if (log.isDebugEnabled()) {
log.debug("[event] connect: username="+event.getUser().getName()+", event="+event);
}
}
@EventListener
public void handleDisconnectEvent(SessionDisconnectEvent event) {
log.info("<=== handleDisconnectEvent: username="+event.getUser().getName()+", event="+event);
if (log.isDebugEnabled()) {
log.debug("[event] disconnect: username="+event.getUser().getName()+", event="+event);
}
}
}
\ No newline at end of file
......@@ -3,6 +3,7 @@ package com.samourai.whirlpool.server.controllers.v1;
import com.samourai.whirlpool.protocol.WhirlpoolProtocol;
import com.samourai.whirlpool.protocol.v1.messages.RegisterInputRequest;
import com.samourai.whirlpool.server.services.RegisterInputService;
import com.samourai.whirlpool.server.utils.Utils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
......@@ -27,7 +28,9 @@ public class RegisterInputController {
@MessageMapping(WhirlpoolProtocol.ENDPOINT_REGISTER_INPUT)
public void registerInputs(@Payload RegisterInputRequest payload, Principal principal) throws Exception {
String username = principal.getName();
log.info("/registerInput: username="+username+", payload="+payload);
if (log.isDebugEnabled()) {
log.debug("[controller] /registerInput: username=" + username + ", payload=" + Utils.toJsonString(payload));
}
// register inputs and send back signed bordereau
registerInputService.registerInput(payload.roundId, username, payload.pubkey, payload.signature, payload.blindedBordereau, payload.utxoHash, payload.utxoIndex, payload.paymentCode, payload.liquidity);
......
......@@ -3,6 +3,7 @@ package com.samourai.whirlpool.server.controllers.v1;
import com.samourai.whirlpool.protocol.WhirlpoolProtocol;
import com.samourai.whirlpool.protocol.v1.messages.RegisterOutputRequest;
import com.samourai.whirlpool.server.services.RegisterOutputService;
import com.samourai.whirlpool.server.utils.Utils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
......@@ -27,7 +28,9 @@ public class RegisterOutputController {
@RequestMapping(value = ENDPOINT, method = RequestMethod.POST)
public void registerOutput(@RequestBody RegisterOutputRequest payload) throws Exception {
log.info("/registerOutput: payload="+payload);
if (log.isDebugEnabled()) {
log.debug("[controller] /registerInput: payload=" + Utils.toJsonString(payload));
}
// register output
registerOutputService.registerOutput(payload.roundId, payload.unblindedSignedBordereau, payload.bordereau, payload.sendAddress, payload.receiveAddress);
......
......@@ -3,6 +3,7 @@ package com.samourai.whirlpool.server.controllers.v1;
import com.samourai.whirlpool.protocol.WhirlpoolProtocol;
import com.samourai.whirlpool.protocol.v1.messages.RegisterOutputRequest;
import com.samourai.whirlpool.server.services.RoundService;
import com.samourai.whirlpool.server.utils.Utils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
......@@ -27,7 +28,9 @@ public class RevealOutputController {
@MessageMapping(WhirlpoolProtocol.ENDPOINT_REVEAL_OUTPUT)
public void revealOutput(@Payload RegisterOutputRequest payload, Principal principal) throws Exception {
String username = principal.getName();
log.info("/revealOutput: username="+username+", payload="+payload);
if (log.isDebugEnabled()) {
log.debug("[controller] /revealOutput: username=" + username + ", payload=" + Utils.toJsonString(payload));
}
// register output
roundService.revealOutput(payload.roundId, username, payload.bordereau);
......
......@@ -28,7 +28,9 @@ public class RoundStatusController {
@MessageMapping(WhirlpoolProtocol.ENDPOINT_ROUND_STATUS)
public void roundStatus(Principal principal) throws Exception {
String username = principal.getName();
log.info("/roundStatus: username="+username);
if (log.isDebugEnabled()) {
log.info("[controller] /roundStatus: username=" + username);
}
// return roundStatus
try {
......
......@@ -3,6 +3,7 @@ package com.samourai.whirlpool.server.controllers.v1;
import com.samourai.whirlpool.protocol.WhirlpoolProtocol;
import com.samourai.whirlpool.protocol.v1.messages.SigningRequest;
import com.samourai.whirlpool.server.services.SigningService;
import com.samourai.whirlpool.server.utils.Utils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
......@@ -27,7 +28,9 @@ public class SigningController {
@MessageMapping(WhirlpoolProtocol.ENDPOINT_SIGNING)
public void signing(@Payload SigningRequest payload, Principal principal) throws Exception {
String username = principal.getName();
log.info("/signing: username="+username+", payload="+payload);
if (log.isDebugEnabled()) {
log.debug("[controller] /signing: username=" + username + ", payload=" + Utils.toJsonString(payload));
}
// signing
signingService.signing(payload.roundId, username, payload.witness);
......
......@@ -79,7 +79,9 @@ public class RegisterInputService {
}
private void checkInputSignature(String roundId, byte[] pubkeyHex, String signature) throws IllegalInputException {
log.info("Verifying signature: " + signature + "\n for pubkey: " + Utils.HEX.encode(pubkeyHex) + "\n for roundId: " + roundId);
if (log.isDebugEnabled()) {
log.debug("Verifying signature: " + signature + "\n for pubkey: " + Utils.HEX.encode(pubkeyHex) + "\n for roundId: " + roundId);
}
// verify signature of 'roundId' for pubkey
if (!cryptoService.verifyMessageSignature(pubkeyHex, roundId, signature)) {
......
......@@ -40,7 +40,9 @@ public class RegisterOutputService {
private void validate(byte[] unblindedSignedBordereau, String bordereau, String sendAddress, String receiveAddress) throws Exception {
// verify bordereau
log.info("Verifying bordereau: "+bordereau+" : "+Base64.encodeBase64String(unblindedSignedBordereau));
if (log.isDebugEnabled()) {
log.debug("Verifying bordereau: " + bordereau + " : " + Base64.encodeBase64String(unblindedSignedBordereau));
}
if (!cryptoService.verifyUnblindedSignedBordereau(bordereau, unblindedSignedBordereau)) {
throw new Exception("Invalid unblindedBordereau");
}
......
......@@ -126,7 +126,9 @@ public class RoundLimitsManager {
}
// adjust mustMix
round.setTargetMustMix(round.getTargetMustMix() - 1);
int nextTargetMustMix = round.getTargetMustMix() - 1;
log.info(" • must-mix-adjust-timeout over, adjusting targetMustMix: "+nextTargetMustMix);
round.setTargetMustMix(nextTargetMustMix);
roundLimitsWatcher.resetTimeout();
checkAddLiquidity(round);
......@@ -167,17 +169,24 @@ public class RoundLimitsManager {
LiquidityPool liquidityPool = getLiquidityPool(round);
int liquiditiesAdded = 0;
int liquiditiesToAdd = round.computeLiquiditiesExpected();
while (liquiditiesAdded < liquiditiesToAdd && liquidityPool.hasLiquidity()) {
log.info("Registering liquidity "+(liquiditiesAdded+1)+"/"+liquiditiesToAdd);
RegisteredLiquidity randomLiquidity = liquidityPool.peekRandomLiquidity();
try {
roundService.addLiquidity(round, randomLiquidity);
liquiditiesAdded++;
} catch (Exception e) {
log.error("registerInput error when adding more liquidity", e);
// ignore the error and continue with more liquidity
if (liquiditiesToAdd > 0) {
// round needs liquidities
while (liquiditiesAdded < liquiditiesToAdd && liquidityPool.hasLiquidity()) {
log.info("Registering liquidity " + (liquiditiesAdded + 1) + "/" + liquiditiesToAdd);
RegisteredLiquidity randomLiquidity = liquidityPool.peekRandomLiquidity();
try {
roundService.addLiquidity(round, randomLiquidity);
liquiditiesAdded++;
} catch (Exception e) {
log.error("registerInput error when adding more liquidity", e);
// ignore the error and continue with more liquidity
}
}
}
else {
// round is ready
roundService.checkRegisterInputReady(round);
}
int missingLiquidities = liquiditiesToAdd - liquiditiesAdded;
if (missingLiquidities > 0) {
......@@ -197,6 +206,7 @@ public class RoundLimitsManager {
}
public void blameForSigningAndResetRound(Round round) {
log.info(" • SIGNING time over (round failed, blaming users who didn't sign...)");
String roundId = round.getRoundId();
// blame users who didn't sign
......
......@@ -14,22 +14,17 @@ import com.samourai.whirlpool.server.exceptions.RoundException;
import com.samourai.whirlpool.server.utils.Utils;
import org.bitcoinj.core.*;
import org.bitcoinj.script.ScriptException;
import org.bouncycastle.util.io.pem.PemObject;
import org.bouncycastle.util.io.pem.PemWriter;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.beans.factory.annotation.Value;
import org.springframework.stereotype.Service;
import java.io.StringWriter;
import java.lang.invoke.MethodHandles;
import java.util.*;
@Service
public class RoundService {
private static final Logger log = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());
//private Map<String,Round> rounds;
private WebSocketService webSocketService;
private CryptoService cryptoService;
private BlameService blameService;
......@@ -73,10 +68,12 @@ public class RoundService {
}
public synchronized void registerInput(String roundId, String username, TxOutPoint input, byte[] pubkey, String paymentCode, byte[] signedBordereauToReply, boolean liquidity) throws IllegalInputException, RoundException {
log.info("registerInput "+roundId+" : "+username+" : "+input);
if (log.isDebugEnabled()) {
log.debug("registerInput "+roundId+" : "+username+" : "+input);
}
Round round = getRound(roundId, RoundStatus.REGISTER_INPUT);
if (!checkInputBalance(input, round, liquidity)) {
throw new IllegalInputException("Input balance should match denomination+fees");
throw new IllegalInputException("Invalid input balance (expected: "+computeSpendAmount(round, liquidity)+", actual:"+input.getValue()+")");
}
RegisteredInput registeredInput = new RegisteredInput(username, input, pubkey, paymentCode, liquidity);
......@@ -98,6 +95,7 @@ public class RoundService {
// queue liquidity for later
RegisteredLiquidity registeredInputQueued = new RegisteredLiquidity(registeredInput, signedBordereauToReply);
liquidityPool.registerLiquidity(registeredInputQueued);
log.info(" • queued liquidity: "+registeredInputQueued.getRegisteredInput().getInput()+" ("+liquidityPool.getNbLiquidities()+" liquidities in pool)");
}
}
......@@ -106,12 +104,15 @@ public class RoundService {
TxOutPoint input = registeredInput.getInput();
String username = registeredInput.getUsername();
int inputsLimit = round.getTargetMustMix();
if (isLiquidity) {
inputsLimit += round.computeLiquiditiesExpected();
if (round.getNbInputsLiquidities() >= round.computeLiquiditiesExpected()) {
throw new RoundException("Round inputs are full, please wait for next round");
}
}
if (round.getNbInputs() >= inputsLimit) {
throw new RoundException("Round inputs are full, please wait for next round");
else {
if (round.getNbInputsMustMix() >= round.getTargetMustMix()) {
throw new RoundException("Round inputs are full, please wait for next round");
}
}
if (round.hasInput(input)) {
throw new IllegalInputException("Input already registered for this round");
......@@ -119,6 +120,7 @@ public class RoundService {
// add immediately to round inputs
round.registerInput(registeredInput);
log.info(" • registered "+(isLiquidity ? "liquidity" : "mustMix")+": " + registeredInput.getInput());
roundLimitsManager.onInputRegistered(round);
// response
......@@ -126,10 +128,7 @@ public class RoundService {
registerInputResponse.signedBordereau = signedBordereauToReply;
webSocketService.sendPrivate(username, registerInputResponse);
if (isRegisterInputReady(round)) {
changeRoundStatus(round.getRoundId(), RoundStatus.REGISTER_OUTPUT);
}
checkRegisterInputReady(round);
}
public void addLiquidity(Round round, RegisteredLiquidity randomLiquidity) throws Exception {
......@@ -154,20 +153,17 @@ public class RoundService {
if (round.getNbInputs() == 0) {
return false;
}
if (!isRegisterInputReadyNbInputs(round.getNbInputs(), round.getTargetMustMix(), round.computeLiquiditiesExpected())) {
if (round.getNbInputsMustMix() != round.getTargetMustMix() || round.getNbInputsLiquidities() != round.computeLiquiditiesExpected()) {
return false;
}
return true;
}
protected synchronized boolean isRegisterInputReadyNbInputs(int nbInputs, int targetMustMix, int nbLiquiditiesExpected) {
int nbInputsExpected = targetMustMix; // mustMix
nbInputsExpected += nbLiquiditiesExpected;
return nbInputs == nbInputsExpected;
}
public synchronized void registerOutput(String roundId, String sendAddress, String receiveAddress, String bordereau) throws Exception {
log.info("addOutput "+roundId+" : "+sendAddress+" "+receiveAddress);
log.info(" • registered output: " + receiveAddress);
if (log.isDebugEnabled()) {
log.debug("sendAddress="+sendAddress);
}
Round round = getRound(roundId, RoundStatus.REGISTER_OUTPUT);
round.registerOutput(sendAddress, receiveAddress, bordereau);
......@@ -177,6 +173,13 @@ public class RoundService {
}
}
public void checkRegisterInputReady(Round round) {
log.info(round.getNbInputsMustMix()+"/"+round.getTargetMustMix()+" mustMix, "+round.getNbInputsLiquidities()+"/"+round.computeLiquiditiesExpected()+" liquidities");
if (isRegisterInputReady(round)) {
changeRoundStatus(round.getRoundId(), RoundStatus.REGISTER_OUTPUT);
}
}
protected void validateOutputs(Round round) throws Exception {
// sendAddresses and receiveAddresses should match (this verifies no user is cheating another one)
if (!Utils.listEqualsIgnoreOrder(round.getSendAddresses(), round.getReceiveAddresses())) {
......@@ -194,7 +197,6 @@ public class RoundService {
}
public synchronized void revealOutput(String roundId, String username, String bordereau) throws RoundException, IllegalInputException {
log.info("revealOutput "+roundId+" : "+bordereau);
Round round = getRound(roundId, RoundStatus.REVEAL_OUTPUT_OR_BLAME);
// verify an output was registered with this bordereau
......@@ -207,6 +209,7 @@ public class RoundService {
throw new IllegalInputException("Bordereau already revealed");
}
round.addRevealedOutputUser(username);
log.info(" • revealed output: username=" + username);
if (isRevealOutputOrBlameReady(round)) {
roundLimitsManager.blameForRevealOutputAndResetRound(round);
......@@ -218,7 +221,7 @@ public class RoundService {
}
public synchronized void registerSignature(String roundId, String username, byte[][] witness) throws Exception {
log.info("setSignaturesByUsername "+roundId+" : "+username);
log.info(" • registered signature: username=" + username);
Round round = getRound(roundId, RoundStatus.SIGNING);
Signature signature = new Signature(witness);
round.setSignatureByUsername(username, signature);
......@@ -227,7 +230,7 @@ public class RoundService {
Transaction tx = round.getTx();
signTransaction(tx, round); // updates Transaction object itself
log.info("Signed tx: "+tx+"\nraw: " + org.bitcoinj.core.Utils.HEX.encode(tx.bitcoinSerialize()));
log.info("Tx to broadcast: \n" + tx + "\nRaw: " + org.bitcoinj.core.Utils.HEX.encode(tx.bitcoinSerialize()));
try {
blockchainDataService.broadcastTransaction(tx);
}
......@@ -255,18 +258,22 @@ public class RoundService {
}
public void changeRoundStatus(String roundId, RoundStatus roundStatus) {
log.info("### changeRoundStatus "+roundId+" ==> "+roundStatus);
log.info("[ROUND "+roundId+"] => "+roundStatus);
try {
Round round = getRound(roundId);
if (roundStatus == RoundStatus.REGISTER_OUTPUT) {
transmitPaymentCodes(round);
} else if (roundStatus == RoundStatus.SIGNING) {
}
else if (roundStatus == RoundStatus.SIGNING) {
try {
Transaction tx = computeTransaction(round);
round.setTx(tx);
log.info("Tx to sign: "+tx+"\nraw: " + org.bitcoinj.core.Utils.HEX.encode(tx.bitcoinSerialize()));
log.info("Txid: "+tx.getHashAsString());
if (log.isDebugEnabled()) {
log.debug("Tx to sign: \n" + tx + "\nRaw: " + org.bitcoinj.core.Utils.HEX.encode(tx.bitcoinSerialize()));
}
} catch (Exception e) {
log.error("Unexpected exception on buildTransaction() for signing", e);
throw new RoundException("System error");
......@@ -466,6 +473,7 @@ public class RoundService {
}
public void goRevealOutputOrBlame(String roundId) {
log.info(" • REGISTER_OUTPUT time over (round failed, blaming users who didn't register output...)");
changeRoundStatus(roundId, RoundStatus.REVEAL_OUTPUT_OR_BLAME);
}
......@@ -485,7 +493,7 @@ public class RoundService {
}
public void __reset(Round round) {
log.info("New round ==> "+round.getRoundId());
log.info("[NEW ROUND "+round.getRoundId()+"]");
if (this.currentRound != null) {
roundLimitsManager.unmanage(round);
}
......
package com.samourai.whirlpool.server.services;
import com.samourai.whirlpool.protocol.WhirlpoolProtocol;
import com.samourai.whirlpool.server.utils.Utils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
......@@ -29,12 +30,16 @@ public class WebSocketService {
}
public void broadcast(Object payload){
//log.info("(broadcast) --> "+payload);
if (log.isDebugEnabled()) {
log.debug("(broadcast) --> "+ Utils.toJsonString(payload));
}
taskExecutor.execute(() -> messagingTemplate.convertAndSend(whirlpoolProtocol.SOCKET_SUBSCRIBE_QUEUE, payload, buildHeaders(payload)));
}
public void sendPrivate(String username, Object payload){
//log.info("(sendPrivate:"+username+") --> "+payload);
if (log.isDebugEnabled()) {
log.debug("(private) --> "+ Utils.toJsonString(payload));
}
taskExecutor.execute(() -> messagingTemplate.convertAndSendToUser(username, whirlpoolProtocol.SOCKET_SUBSCRIBE_USER_REPLY, payload, buildHeaders(payload)));
}
......
......@@ -11,8 +11,8 @@ public class RoundTO {
public RoundTO(Round round, RoundResult roundResult) {
this.roundId = round.getRoundId();
this.nbMustMix = round.getNbInputs() - this.nbLiquidities;
this.nbLiquidities = (int)round.getInputs().parallelStream().filter(input -> input.isLiquidity()).count();
this.nbMustMix = round.getNbInputsMustMix();
this.nbLiquidities = round.getNbInputsLiquidities();
this.roundResult = roundResult;
}
......
package com.samourai.whirlpool.server.utils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import java.lang.reflect.Field;
import java.lang.reflect.Method;
/**
* Contains methods to access and manipulate logback framework dynamically at run-time. Here 'dynamically' means without
* referencing the logback JAR, but using it if found in the classpath.
*
* @author Muhammed Demirbas
* @since 19 Mar 2013
*/
public final class LogbackUtils
{
public static final String LOGBACK_CLASSIC = "ch.qos.logback.classic";
public static final String LOGBACK_CLASSIC_LOGGER = "ch.qos.logback.classic.Logger";
public static final String LOGBACK_CLASSIC_LEVEL = "ch.qos.logback.classic.Level";
private static final Logger logger = LoggerFactory.getLogger(LogbackUtils.class);
private LogbackUtils()
{
// Prevent instance creation
}
/**