Skip to content

Conversation

@hiranya911
Copy link
Contributor

@hiranya911 hiranya911 commented Mar 20, 2018

Removing the deprecated com.google.firebase.database.logging package, and using SLF4J as the primary logging facade.

Some sample debug logs obtained with SLF4J and java.util.logging:

2018-03-20 11:53:50 FINE com.google.firebase.FirebaseApp$TokenRefresher start Starting the proactive token refresher
2018-03-20 11:53:50 FINE com.google.firebase.FirebaseApp$TokenRefresher scheduleNext Scheduling next token refresh in 0 milliseconds
2018-03-20 11:53:50 FINE com.google.firebase.FirebaseApp$TokenRefresher$1 call Refreshing OAuth2 credential
2018-03-20 11:53:50 FINE com.google.firebase.FirebaseApp$TokenRefresher scheduleNext Scheduling next token refresh in 3299999 milliseconds
2018-03-20 11:53:50 FINE com.google.firebase.database.connection.PersistentConnectionImpl tryScheduleReconnect [pc_0] Scheduling connection attempt
2018-03-20 11:53:50 FINE com.google.firebase.database.connection.util.RetryHelper retry Scheduling retry in 0ms
2018-03-20 11:53:50 FINE com.google.firebase.database.connection.PersistentConnectionImpl listen [pc_0] Listening on foo (params: {})
2018-03-20 11:53:50 FINE com.google.firebase.database.connection.PersistentConnectionImpl listen [pc_0] Adding listen query: foo (params: {})
2018-03-20 11:53:50 FINE com.google.firebase.database.connection.PersistentConnectionImpl$1 run [pc_0] Trying to fetch auth token
2018-03-20 11:53:50 FINE com.google.firebase.database.connection.PersistentConnectionImpl$1$1 onSuccess [pc_0] Successfully fetched token, opening connection
2018-03-20 11:53:50 FINE com.google.firebase.database.connection.Connection open [conn_0] Opening a connection
2018-03-20 11:53:51 FINE com.google.firebase.database.core.Repo setValue set: /foo 1521572031090
2018-03-20 11:53:51 FINE com.google.firebase.database.core.view.EventRaiser raiseEvents Raising 1 event(s)
2018-03-20 11:53:51 FINE com.google.firebase.database.core.view.EventRaiser$1 run Raising /foo: VALUE: 1521572031090
2018-03-20 11:53:51 FINE com.google.firebase.database.core.Repo abortTransactions Aborting transactions for path: /foo. Affected: /foo
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.WebsocketConnection$WSClientHandlerImpl onOpen [ws_0] Websocket opened
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.WebsocketConnection resetKeepAlive [ws_0] Reset keepAlive
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.WebsocketConnection$WSClientHandlerImpl onMessage [ws_0] WS message: {"t":"c","d":{"t":"h","d":{"ts":1521572031078,"v":"5","h":"s-usc1c-nss-256.firebaseio.com","s":"99R2JhKnw6n0sTpih6zqDO0NuGe3imhv"}}}
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.WebsocketConnection resetKeepAlive [ws_0] Reset keepAlive. Remaining: 44998
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.WebsocketConnection handleNewFrameCount [ws_0] Handle new frame count: 1
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.WebsocketConnection appendFrame [ws_0] Parsed complete frame: {t=c, d={t=h, d={h=s-usc1c-nss-256.firebaseio.com, s=99R2JhKnw6n0sTpih6zqDO0NuGe3imhv, v=5, ts=1521572031078}}}
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.Connection onControlMessage [conn_0] Got control message: {t=h, d={h=s-usc1c-nss-256.firebaseio.com, s=99R2JhKnw6n0sTpih6zqDO0NuGe3imhv, v=5, ts=1521572031078}}
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.Connection onConnectionReady [conn_0] Realtime connection established
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.PersistentConnectionImpl onReady [pc_0] onReady
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.PersistentConnectionImpl handleTimestamp [pc_0] Handling timestamp
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.PersistentConnectionImpl sendConnectStats [pc_0] Sending first connection stats
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.Connection sendData [conn_0] Sending data: {t=d, d={a=s, r=0, b={c={sdk.admin_java.5-9-1-SNAPSHOT=1}}}}
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.WebsocketConnection resetKeepAlive [ws_0] Reset keepAlive. Remaining: 44996
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.PersistentConnectionImpl restoreAuth [pc_0] Calling restore state
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.PersistentConnectionImpl restoreAuth [pc_0] Restoring auth.
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.Connection sendData [conn_0] Sending data (contents hidden)
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.WebsocketConnection resetKeepAlive [ws_0] Reset keepAlive. Remaining: 44997
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.WebsocketConnection$WSClientHandlerImpl onMessage [ws_0] WS message: {"t":"d","d":{"r":0,"b":{"s":"ok","d":""}}}
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.WebsocketConnection resetKeepAlive [ws_0] Reset keepAlive. Remaining: 44946
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.WebsocketConnection handleNewFrameCount [ws_0] Handle new frame count: 1
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.WebsocketConnection appendFrame [ws_0] Parsed complete frame: {t=d, d={r=0, b={d=, s=ok}}}
2018-03-20 11:53:51 FINE com.google.firebase.database.connection.Connection onDataMessage [conn_0] Received data message: {r=0, b={d=, s=ok}}
2018-03-20 11:53:51 FINE

Same with the SLF4J simple logger:

[main] DEBUG com.google.firebase.FirebaseApp - Starting the proactive token refresher
[main] DEBUG com.google.firebase.FirebaseApp - Scheduling next token refresh in 0 milliseconds
[firebase-scheduled-worker] DEBUG com.google.firebase.FirebaseApp - Refreshing OAuth2 credential
[firebase-scheduled-worker] DEBUG com.google.firebase.FirebaseApp - Scheduling next token refresh in 3299999 milliseconds
[firebase-database-worker] DEBUG com.google.firebase.database.connection.PersistentConnection - [pc_0] Scheduling connection attempt
[firebase-database-worker] DEBUG com.google.firebase.database.connection.util.RetryHelper - Scheduling retry in 0ms
[firebase-database-worker] DEBUG com.google.firebase.database.connection.PersistentConnection - [pc_0] Listening on foo (params: {})
[firebase-database-worker] DEBUG com.google.firebase.database.connection.PersistentConnection - [pc_0] Adding listen query: foo (params: {})
[firebase-database-worker] DEBUG com.google.firebase.database.connection.PersistentConnection - [pc_0] Trying to fetch auth token
[firebase-database-worker] DEBUG com.google.firebase.database.connection.PersistentConnection - [pc_0] Successfully fetched token, opening connection
[firebase-database-worker] DEBUG com.google.firebase.database.core.Repo - set: /foo 1521572606467
[firebase-database-worker] DEBUG com.google.firebase.database.core.view.EventRaiser - Raising 1 event(s)
[firebase-database-event-target] DEBUG com.google.firebase.database.core.view.EventRaiser - Raising /foo: VALUE: 1521572606467
[firebase-database-worker] DEBUG com.google.firebase.database.core.Repo - Aborting transactions for path: /foo. Affected: /foo
[firebase-websocket-worker] DEBUG io.netty.handler.ssl.SslHandler - [id: 0x747d73bb, L:/172.18.44.82:32840 - R:admin-java-integration.firebaseio.com/35.201.97.85:443] HANDSHAKEN: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
[firebase-websocket-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Websocket opened
[firebase-database-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Reset keepAlive
[firebase-websocket-worker] DEBUG io.netty.handler.codec.http.websocketx.WebSocket08FrameDecoder - Decoding WebSocket Frame opCode=1
[firebase-websocket-worker] DEBUG io.netty.handler.codec.http.websocketx.WebSocket08FrameDecoder - Decoding WebSocket Frame length=132
[firebase-websocket-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] WS message: {"t":"c","d":{"t":"h","d":{"ts":1521572606524,"v":"5","h":"s-usc1c-nss-256.firebaseio.com","s":"7p9ho06FGNMsdbF5ywyoAGlqAhNW20lw"}}}
[firebase-database-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Reset keepAlive. Remaining: 44997
[firebase-database-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Handle new frame count: 1
[firebase-database-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Parsed complete frame: {t=c, d={t=h, d={h=s-usc1c-nss-256.firebaseio.com, s=7p9ho06FGNMsdbF5ywyoAGlqAhNW20lw, v=5, ts=1521572606524}}}
[firebase-database-worker] DEBUG com.google.firebase.database.connection.Connection - [conn_0] Got control message: {t=h, d={h=s-usc1c-nss-256.firebaseio.com, s=7p9ho06FGNMsdbF5ywyoAGlqAhNW20lw, v=5, ts=1521572606524}}
[firebase-database-worker] DEBUG com.google.firebase.database.connection.Connection - [conn_0] Realtime connection established
[firebase-database-worker] DEBUG com.google.firebase.database.connection.PersistentConnection - [pc_0] onReady
[firebase-database-worker] DEBUG com.google.firebase.database.connection.PersistentConnection - [pc_0] Handling timestamp
[firebase-database-worker] DEBUG com.google.firebase.database.connection.PersistentConnection - [pc_0] Sending first connection stats
[firebase-database-worker] DEBUG com.google.firebase.database.connection.Connection - [conn_0] Sending data: {t=d, d={a=s, r=0, b={c={sdk.admin_java.5-9-1-SNAPSHOT=1}}}}
[firebase-database-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Reset keepAlive. Remaining: 44996
[firebase-database-worker] DEBUG com.google.firebase.database.connection.PersistentConnection - [pc_0] Calling restore state
[firebase-database-worker] DEBUG com.google.firebase.database.connection.PersistentConnection - [pc_0] Restoring auth.
[firebase-websocket-worker] DEBUG io.netty.handler.codec.http.websocketx.WebSocket08FrameEncoder - Encoding WebSocket Frame opCode=1 length=75
[firebase-database-worker] DEBUG com.google.firebase.database.connection.Connection - [conn_0] Sending data (contents hidden)
[firebase-database-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Reset keepAlive. Remaining: 44996
[firebase-websocket-worker] DEBUG io.netty.handler.codec.http.websocketx.WebSocket08FrameEncoder - Encoding WebSocket Frame opCode=1 length=191
[firebase-websocket-worker] DEBUG io.netty.handler.codec.http.websocketx.WebSocket08FrameDecoder - Decoding WebSocket Frame opCode=1
[firebase-websocket-worker] DEBUG io.netty.handler.codec.http.websocketx.WebSocket08FrameDecoder - Decoding WebSocket Frame length=43
[firebase-websocket-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] WS message: {"t":"d","d":{"r":0,"b":{"s":"ok","d":""}}}
[firebase-database-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Reset keepAlive. Remaining: 44945
[firebase-database-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Handle new frame count: 1
[firebase-database-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Parsed complete frame: {t=d, d={r=0, b={d=, s=ok}}}
[firebase-database-worker] DEBUG com.google.firebase.database.connection.Connection - [conn_0] Received data message: {r=0, b={d=, s=ok}}
[firebase-websocket-worker] DEBUG io.netty.handler.codec.http.websocketx.WebSocket08FrameDecoder - Decoding WebSocket Frame opCode=1
[firebase-websocket-worker] DEBUG io.netty.handler.codec.http.websocketx.WebSocket08FrameDecoder - Decoding WebSocket Frame length=75
[firebase-websocket-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] WS message: {"t":"d","d":{"r":1,"b":{"s":"ok","d":{"auth":null,"expires":1521576206}}}}
[firebase-database-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Reset keepAlive. Remaining: 44957
[firebase-database-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Handle new frame count: 1
[firebase-database-worker] DEBUG com.google.firebase.database.connection.WebsocketConnection - [ws_0] Parsed complete frame: {t=d, d={r=1, b={d={auth=null, expires=1521576206}, s=ok}}}

@Override
public void onKill(String reason) {
if (logger.logsDebug()) {
if (logger.isDebugEnabled()) {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You should be able to remove this check here as well with minimal performance penalty.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

if (logger.logsDebug()) {
logger.debug("removing query " + query);
}
logger.debug("removing query {}", query);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Label missing.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

private static final String TRANSACTION_TOO_MANY_RETRIES = "maxretries";
private static final String TRANSACTION_OVERRIDE_BY_SET = "overriddenBySet";

private static final Logger operationLogger = LoggerFactory.getLogger(Repo.class);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You are now using this in places were you previously used 'transactionLogger'. I'd suggest naming this just 'logger'.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Done

@hiranya911 hiranya911 merged commit 559ce44 into v6 Mar 23, 2018
@hiranya911 hiranya911 deleted the hkj-slf4j branch March 23, 2018 00:10
hiranya911 added a commit that referenced this pull request May 7, 2018
* Adding the sync APIs for FirebaseAuth

* Added more tests; Added sync APIs for FirebaseMessaging

* Removing Task references from database, iid and fcm APIs

* Fixing a typo

* Minor code clean up

* Updated javadocs; Renamed internal helpers of FirebaseMessaging for consistency

* Removed the deprecated FirebaseCredential API (#149)

* Removing the Task API (#152)

* Removed the deprecated FirebaseCredential API

* Removing the deprecated Task API

* Dropping Support for App Engine Java 7 Runtime (#153)

* Dropping support for GAE 7

* Removed GaeThreadFactory, GaeExecutorService and RevivingScheduledExecutor

* Removed the deprecated FirebaseCredential API

* Removing GAE java7 related APIs (GaeThreadFactory, RevivingScheduledExecutor)

* Removed GaePlatform implementation

* Added FirebaseScheduledExecutor

* Updated documentation

* Some minor nits from code reviews

* Calling super method in DefaultRunLoop executor

* Removing Deprecated LogWrapper API (#154)

* Dropping support for GAE 7

* Removed GaeThreadFactory, GaeExecutorService and RevivingScheduledExecutor

* Removed the deprecated FirebaseCredential API

* Removing GAE java7 related APIs (GaeThreadFactory, RevivingScheduledExecutor)

* Removed GaePlatform implementation

* Added FirebaseScheduledExecutor

* Updated documentation

* Removing LogWrapper API

* Removing PrefixedLogger

* Removing test config file

* Updated CHANGELOG

* Minor clean ups pointed out in the code review

* Minor API doc fixes (#171)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants