Skip to content

Commit 0878f4e

Browse files
author
lhoriman
committed
Improved logging.
git-svn-id: https://objectify-appengine.googlecode.com/svn/branches/fluent@950 79e2b5ea-dad9-11de-b64b-7d26b27941e2
1 parent 57ed53c commit 0878f4e

File tree

11 files changed

+212
-12
lines changed

11 files changed

+212
-12
lines changed

‎logging.properties

+1
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,7 @@
77

88
handlers= java.util.logging.ConsoleHandler
99
java.util.logging.ConsoleHandler.level = FINEST
10+
java.util.logging.ConsoleHandler.formatter = com.googlecode.objectify.test.util.ReallySimpleFormatter
1011

1112
.level = WARNING
1213
com.googlecode.objectify.level = FINEST

‎src-test/com/googlecode/objectify/test/LoadParentTestsReallySimple.java

+70
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,70 @@
1+
/*
2+
*/
3+
4+
package com.googlecode.objectify.test;
5+
6+
import org.testng.annotations.Test;
7+
8+
import com.googlecode.objectify.Key;
9+
import com.googlecode.objectify.Ref;
10+
import com.googlecode.objectify.annotation.Entity;
11+
import com.googlecode.objectify.annotation.Id;
12+
import com.googlecode.objectify.annotation.Load;
13+
import com.googlecode.objectify.annotation.Parent;
14+
import com.googlecode.objectify.test.util.TestBase;
15+
import com.googlecode.objectify.test.util.TestObjectify;
16+
17+
/**
18+
* Absolute simplest parent reference tests.
19+
*
20+
* @author Jeff Schnitzer <[email protected]>
21+
*/
22+
public class LoadParentTestsReallySimple extends TestBase
23+
{
24+
/** */
25+
@Entity
26+
public static class Father {
27+
public @Id Long id;
28+
29+
@Override
30+
public String toString() {
31+
return this.getClass().getSimpleName() + "(" + id + ")";
32+
}
33+
}
34+
35+
/** */
36+
@Entity
37+
public static class Child {
38+
public @Id Long id;
39+
public @Load @Parent Father father;
40+
41+
@Override
42+
public String toString() {
43+
return this.getClass().getSimpleName() + "(" + id + ", " + father + ")";
44+
}
45+
}
46+
47+
/** */
48+
@Test
49+
public void testParentExists() throws Exception
50+
{
51+
fact.register(Father.class);
52+
fact.register(Child.class);
53+
54+
TestObjectify ofy = fact.begin();
55+
56+
Father f = new Father();
57+
ofy.put(f);
58+
59+
Child ch = new Child();
60+
ch.father = f;
61+
Key<Child> kch = ofy.put(ch);
62+
63+
ofy.clear();
64+
65+
Ref<Child> ref = ofy.load().key(kch);
66+
Child fetched = ref.get();
67+
68+
assert fetched.father.id.equals(f.id);
69+
}
70+
}

‎src-test/com/googlecode/objectify/test/util/ReallySimpleFormatter.java

+45
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,45 @@
1+
/*
2+
*/
3+
4+
package com.googlecode.objectify.test.util;
5+
6+
import java.util.logging.LogRecord;
7+
import java.util.logging.SimpleFormatter;
8+
9+
/**
10+
* A formatter that makes it easier to read log messages
11+
*
12+
* @author Jeff Schnitzer <[email protected]>
13+
*/
14+
public class ReallySimpleFormatter extends SimpleFormatter
15+
{
16+
static final int MESSAGE_COLUMN = 60;
17+
18+
@Override
19+
public synchronized String format(LogRecord record)
20+
{
21+
StringBuilder bld = new StringBuilder();
22+
23+
// Log level
24+
bld.append(record.getLevel()).append(": ");
25+
26+
// Class.method using shortName
27+
String className = record.getSourceClassName();
28+
className = className.substring(className.lastIndexOf('.')+1);
29+
bld.append(className).append('.').append(record.getSourceMethodName()).append(": ");
30+
31+
if (bld.length() < MESSAGE_COLUMN)
32+
while (bld.length() < MESSAGE_COLUMN)
33+
bld.append(' ');
34+
else
35+
bld.append('\t');
36+
37+
// The message
38+
bld.append(record.getMessage());
39+
40+
// Newline
41+
bld.append('\n');
42+
43+
return bld.toString();
44+
}
45+
}

‎src/com/googlecode/objectify/impl/KeyMetadata.java

+13-2
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,8 @@
22

33
import java.lang.reflect.Field;
44
import java.util.Set;
5+
import java.util.logging.Level;
6+
import java.util.logging.Logger;
57

68
import com.google.appengine.api.datastore.Entity;
79
import com.googlecode.objectify.Key;
@@ -23,6 +25,9 @@
2325
*/
2426
public class KeyMetadata<T>
2527
{
28+
/** */
29+
private static final Logger log = Logger.getLogger(KeyMetadata.class.getName());
30+
2631
/** */
2732
protected ObjectifyFactory fact;
2833

@@ -139,9 +144,12 @@ public Entity initEntity(T pojo)
139144
{
140145
Object id = getId(pojo);
141146
if (id == null)
142-
if (isIdNumeric())
147+
if (isIdNumeric()) {
148+
if (log.isLoggable(Level.FINEST))
149+
log.finest("Getting parent key from " + pojo);
150+
143151
return new Entity(this.kind, getParentRaw(pojo));
144-
else
152+
} else
145153
throw new IllegalStateException("Cannot save an entity with a null String @Id: " + pojo);
146154
else
147155
return new Entity(getRawKey(pojo));
@@ -154,6 +162,9 @@ public Entity initEntity(T pojo)
154162
* @throws IllegalArgumentException if obj has a null id
155163
*/
156164
public com.google.appengine.api.datastore.Key getRawKey(T pojo) {
165+
166+
if (log.isLoggable(Level.FINEST))
167+
log.finest("Getting key from " + pojo);
157168

158169
if (!this.entityClass.isAssignableFrom(pojo.getClass()))
159170
throw new IllegalArgumentException("Trying to use metadata for " + this.entityClass.getName() + " to get key of " + pojo.getClass().getName());

‎src/com/googlecode/objectify/impl/Node.java

-2
Original file line numberDiff line numberDiff line change
@@ -241,8 +241,6 @@ private Map<String, Node> map() {
241241
public String toString() {
242242
StringBuilder bld = new StringBuilder();
243243

244-
bld.append(path.toPathString()).append(':');
245-
246244
if (hasPropertyValue())
247245
bld.append('{').append(getPropertyValue()).append('}');
248246

‎src/com/googlecode/objectify/impl/Transmog.java

+12
Original file line numberDiff line numberDiff line change
@@ -7,6 +7,8 @@
77
import java.util.List;
88
import java.util.Map;
99
import java.util.Set;
10+
import java.util.logging.Level;
11+
import java.util.logging.Logger;
1012

1113
import com.google.appengine.api.datastore.Entity;
1214
import com.googlecode.objectify.LoadException;
@@ -28,6 +30,9 @@
2830
*/
2931
public class Transmog<T>
3032
{
33+
/** */
34+
private static final Logger log = Logger.getLogger(Transmog.class.getName());
35+
3136
/** The root translator that knows how to deal with an object of type T */
3237
Translator<T> rootTranslator;
3338

@@ -81,6 +86,9 @@ public T load(Node root, LoadContext ctx) throws LoadException {
8186
*/
8287
public Entity save(T fromPojo, Objectify ofy)
8388
{
89+
if (log.isLoggable(Level.FINEST))
90+
log.finest("\tTranslating " + fromPojo);
91+
8492
try {
8593
Node root = save(fromPojo, new SaveContext(ofy));
8694
Entity entity = save(root);
@@ -114,6 +122,10 @@ public Node save(T fromPojo, SaveContext ctx) {
114122
* @return a root Node corresponding to the Entity, in a format suitable for translators.
115123
*/
116124
public Node load(Entity fromEntity) {
125+
126+
if (log.isLoggable(Level.FINEST))
127+
log.finest("\tTranslating " + fromEntity);
128+
117129
Node root = this.loadLiterally(fromEntity);
118130

119131
// No embed collections? No changes necessary, we can optimize out the graph walk

‎src/com/googlecode/objectify/impl/engine/Engine.java

+11
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,8 @@
66
import java.util.List;
77
import java.util.Map;
88
import java.util.concurrent.Future;
9+
import java.util.logging.Level;
10+
import java.util.logging.Logger;
911

1012
import com.google.appengine.api.datastore.AsyncDatastoreService;
1113
import com.google.appengine.api.datastore.Entity;
@@ -36,6 +38,9 @@
3638
*/
3739
public class Engine
3840
{
41+
/** */
42+
private static final Logger log = Logger.getLogger(Engine.class.getName());
43+
3944
/** */
4045
protected ObjectifyImpl ofy;
4146

@@ -59,6 +64,9 @@ public Engine(ObjectifyImpl ofy, AsyncDatastoreService ads, Session session) {
5964
*/
6065
public <K, E extends K> Result<Map<Key<K>, E>> save(final Iterable<? extends E> entities) {
6166

67+
if (log.isLoggable(Level.FINEST))
68+
log.finest("Saving " + entities);
69+
6270
List<Entity> entityList = new ArrayList<Entity>();
6371
for (E obj: entities) {
6472
if (obj instanceof Entity) {
@@ -100,6 +108,9 @@ protected Map<Key<K>, E> wrap(List<com.google.appengine.api.datastore.Key> base)
100108
session.add(sent);
101109
}
102110

111+
if (log.isLoggable(Level.FINEST))
112+
log.finest("Saved " + base);
113+
103114
return result;
104115
}
105116
};

‎src/com/googlecode/objectify/impl/engine/LoadBatch.java

+11
Original file line numberDiff line numberDiff line change
@@ -59,6 +59,11 @@ public <T> Result<T> get(final Key<T> key) {
5959
public T now() {
6060
return (T)translated.now().get(key);
6161
}
62+
63+
@Override
64+
public String toString() {
65+
return "(Round Result of " + key + ")";
66+
}
6267
};
6368
}
6469

@@ -93,6 +98,12 @@ protected Map<Key<?>, Object> wrap(Map<com.google.appengine.api.datastore.Key, E
9398

9499
return result;
95100
}
101+
102+
/** Helpful when debugging */
103+
@Override
104+
public String toString() {
105+
return "(Round translated ResultWrapper for " + pending + ")";
106+
}
96107
};
97108
}
98109

‎src/com/googlecode/objectify/impl/translate/AbstractTranslator.java

+3-2
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@
55

66
import com.googlecode.objectify.impl.Node;
77
import com.googlecode.objectify.impl.Path;
8+
import com.googlecode.objectify.util.LogUtils;
89

910
/**
1011
* <p>Very simple helper for all kinds of translators.</p>
@@ -24,7 +25,7 @@ final public T load(Node node, LoadContext ctx) {
2425
T obj = this.loadAbstract(node, ctx);
2526

2627
if (log.isLoggable(Level.FINEST))
27-
log.finest("Load: Translated " + node + " to " + obj);
28+
log.logp(Level.FINEST, this.getClass().getName(), "load", LogUtils.msg(node.getPath(), "Loaded " + node + " to " + obj));
2829

2930
return obj;
3031
}
@@ -37,7 +38,7 @@ final public Node save(T pojo, Path path, boolean index, SaveContext ctx) {
3738
Node n = this.saveAbstract(pojo, path, index, ctx);
3839

3940
if (log.isLoggable(Level.FINEST))
40-
log.finest("Save: Translated " + pojo + " to " + n);
41+
log.logp(Level.FINEST, this.getClass().getName(), "save", LogUtils.msg(path, "Saved " + pojo + " to " + n));
4142

4243
return n;
4344
};

‎src/com/googlecode/objectify/impl/translate/EmbedTranslatorFactory.java

+12-6
Original file line numberDiff line numberDiff line change
@@ -20,6 +20,7 @@
2020
import com.googlecode.objectify.impl.translate.CollectionTranslatorFactory.CollectionListNodeTranslator;
2121
import com.googlecode.objectify.impl.translate.MapTranslatorFactory.MapMapNodeTranslator;
2222
import com.googlecode.objectify.repackaged.gentyref.GenericTypeReflector;
23+
import com.googlecode.objectify.util.LogUtils;
2324

2425

2526
/**
@@ -78,7 +79,7 @@ else if (translator instanceof MapMapNodeTranslator && actual.hasMap()) {
7879
value = translator.load(actual, ctx);
7980
}
8081

81-
setOnPojo(onPojo, value, ctx);
82+
setOnPojo(onPojo, value, ctx, node.getPath());
8283
}
8384
catch (SkipException ex) {
8485
// No prob, skip this one
@@ -90,25 +91,30 @@ else if (translator instanceof MapMapNodeTranslator && actual.hasMap()) {
9091
* Sets the property on the pojo to the value. However, sensitive to the value possibly being a Result<?>
9192
* wrapper, in which case it enqueues the set operation until the loadcontext is done.
9293
*/
93-
private void setOnPojo(final Object pojo, final Object value, LoadContext ctx) {
94+
private void setOnPojo(final Object pojo, final Object value, LoadContext ctx, final Path path) {
9495
if (value instanceof Result) {
9596
if (log.isLoggable(Level.FINEST))
96-
log.finest("Delaying set property " + property.getName());
97+
log.finest(LogUtils.msg(path, "Delaying set property " + property.getName()));
9798

9899
ctx.delay(new Runnable() {
99100
@Override
100101
public void run() {
101102
Object actualValue = ((Result<?>)value).now();
102103

103104
if (log.isLoggable(Level.FINEST))
104-
log.finest("Setting delayed property " + property.getName() + " to " + actualValue);
105+
log.finest(LogUtils.msg(path, "Setting delayed property " + property.getName() + " to " + actualValue));
105106

106107
property.set(pojo, actualValue);
107108
}
109+
110+
@Override
111+
public String toString() {
112+
return "(delayed Runnable to set " + property.getName() + ")";
113+
}
108114
});
109115
} else {
110116
if (log.isLoggable(Level.FINEST))
111-
log.finest("Setting property " + property.getName() + " to " + value);
117+
log.finest(LogUtils.msg(path, "Setting property " + property.getName() + " to " + value));
112118

113119
property.set(pojo, value);
114120
}
@@ -220,7 +226,7 @@ public Translator<T> create(final Path path, final Annotation[] fieldAnnotations
220226
@Override
221227
protected T loadMap(Node node, LoadContext ctx) {
222228
if (log.isLoggable(Level.FINEST))
223-
log.finest("Instantiating a " + clazz.getName());
229+
log.finest(LogUtils.msg(node.getPath(), "Instantiating a " + clazz.getName()));
224230

225231
T pojo = fact.construct(clazz);
226232

0 commit comments

Comments
 (0)