001/*
002 * (C) Copyright 2006-2017 Nuxeo (http://nuxeo.com/) and others.
003 *
004 * Licensed under the Apache License, Version 2.0 (the "License");
005 * you may not use this file except in compliance with the License.
006 * You may obtain a copy of the License at
007 *
008 *     http://www.apache.org/licenses/LICENSE-2.0
009 *
010 * Unless required by applicable law or agreed to in writing, software
011 * distributed under the License is distributed on an "AS IS" BASIS,
012 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
013 * See the License for the specific language governing permissions and
014 * limitations under the License.
015 *
016 * Contributors:
017 *     Florent Guillaume
018 */
019package org.nuxeo.ecm.core.storage.sql.jdbc;
020
021import java.io.Serializable;
022import java.sql.ResultSet;
023import java.sql.SQLException;
024import java.util.ArrayList;
025import java.util.Calendar;
026import java.util.Collection;
027import java.util.Collections;
028import java.util.LinkedList;
029import java.util.List;
030import java.util.Map;
031import java.util.stream.Collectors;
032
033import org.apache.commons.logging.Log;
034import org.apache.commons.logging.LogFactory;
035import org.nuxeo.ecm.core.api.model.Delta;
036import org.nuxeo.ecm.core.storage.sql.Model;
037import org.nuxeo.ecm.core.storage.sql.Row;
038import org.nuxeo.ecm.core.storage.sql.jdbc.db.Column;
039
040/**
041 * Logger used for debugging.
042 */
043public class JDBCLogger {
044
045    public static final Log log = LogFactory.getLog(JDBCLogger.class);
046
047    public static final int DEBUG_MAX_STRING = 100;
048
049    public static final int DEBUG_MAX_ARRAY = 10;
050
051    public final String instance;
052
053    public JDBCLogger(String instance) {
054        this.instance = instance;
055    }
056
057    public boolean isLogEnabled() {
058        return log.isTraceEnabled();
059    }
060
061    public String formatMessage(String message) {
062        return "(" + instance + ") SQL: " + message;
063    }
064
065    public void error(String message) {
066        log.error(formatMessage(message));
067    }
068
069    public void error(String message, Throwable t) {
070        log.error(formatMessage(message), t);
071    }
072
073    public void warn(String message) {
074        log.warn(formatMessage(message));
075    }
076
077    public void info(String message) {
078        log.info(formatMessage(message));
079    }
080
081    public void log(String message) {
082        log.trace(formatMessage(message));
083    }
084
085    public void logCount(int count) {
086        if (count > 0 && isLogEnabled()) {
087            log("  -> " + count + " row" + (count > 1 ? "s" : ""));
088        }
089    }
090
091    public void logResultSet(ResultSet rs, List<Column> columns) throws SQLException {
092        List<String> res = new LinkedList<>();
093        int i = 0;
094        for (Column column : columns) {
095            i++;
096            Serializable v = column.getFromResultSet(rs, i);
097            res.add(column.getKey() + "=" + loggedValue(v));
098        }
099        log("  -> " + String.join(", ", res));
100    }
101
102    public void logMap(Map<String, Serializable> map) throws SQLException {
103        String result = map.entrySet()
104                           .stream()
105                           .map(entry -> entry.getKey() + "=" + loggedValue(entry.getValue()))
106                           .collect(Collectors.joining(", "));
107        log("  -> " + result);
108    }
109
110    public void logMaps(List<Map<String, Serializable>> maps, boolean countTotal, long totalSize) {
111        List<Map<String, Serializable>> debugMaps = maps;
112        String end = "";
113        if (maps.size() > DEBUG_MAX_ARRAY) {
114            debugMaps = new ArrayList<>(DEBUG_MAX_ARRAY);
115            int i = 0;
116            for (Map<String, Serializable> map : maps) {
117                debugMaps.add(map);
118                i++;
119                if (i == DEBUG_MAX_ARRAY) {
120                    break;
121                }
122            }
123            end = "...(" + maps.size() + " ids)...";
124        }
125        if (countTotal) {
126            end += " (total " + totalSize + ')';
127        }
128        String result = debugMaps.stream()
129                                 .map(map -> map.entrySet()
130                                                .stream()
131                                                .map(entry -> entry.getKey() + "=" + loggedValue(entry.getValue()))
132                                                .collect(Collectors.joining(", ")))
133                                 .collect(Collectors.joining(",", "{", "}"));
134        log("  -> " + result + end);
135    }
136
137    public void logIds(List<Serializable> ids, boolean countTotal, long totalSize) {
138        List<Serializable> debugIds = ids;
139        String end = "";
140        if (ids.size() > DEBUG_MAX_ARRAY) {
141            debugIds = new ArrayList<>(DEBUG_MAX_ARRAY);
142            int i = 0;
143            for (Serializable id : ids) {
144                debugIds.add(id);
145                i++;
146                if (i == DEBUG_MAX_ARRAY) {
147                    break;
148                }
149            }
150            end = "...(" + ids.size() + " ids)...";
151        }
152        if (countTotal) {
153            end += " (total " + totalSize + ')';
154        }
155        log("  -> " + debugIds + end);
156    }
157
158    public void logSQL(String sql, List<Column> columns, Row row) {
159        logSQL(sql, columns, row, Collections.emptyList(), Collections.emptyMap());
160    }
161
162    public void logSQL(String sql, List<Column> columns, Row row, List<Column> whereColumns,
163            Map<String, Serializable> conditions) {
164        List<Serializable> values = new ArrayList<>();
165        for (Column column : columns) {
166            String key = column.getKey();
167            Serializable value = row.get(key);
168            if (value instanceof Delta) {
169                Delta delta = (Delta) value;
170                if (delta.getBase() != null) {
171                    value = delta.getDeltaValue();
172                }
173            }
174            values.add(value);
175        }
176        for (Column column : whereColumns) {
177            String key = column.getKey();
178            Serializable value;
179            if (column.getKey().equals(Model.MAIN_KEY)) {
180                value = row.get(key);
181            } else {
182                value = conditions.get(key);
183            }
184            values.add(value);
185        }
186        logSQL(sql, values);
187    }
188
189    // callable statement with one return value
190    private static final String CALLABLE_START = "{?=";
191
192    public void logSQL(String sql, Collection<Serializable> values) {
193        StringBuilder buf = new StringBuilder();
194        int start = 0;
195        if (sql.startsWith(CALLABLE_START)) {
196            buf.append(CALLABLE_START);
197            start = CALLABLE_START.length();
198        }
199        for (Serializable v : values) {
200            int index = sql.indexOf('?', start);
201            if (index == -1) {
202                // mismatch between number of ? and number of values
203                break;
204            }
205            buf.append(sql, start, index);
206            buf.append(loggedValue(v));
207            start = index + 1;
208        }
209        buf.append(sql, start, sql.length());
210        log(buf.toString());
211    }
212
213    /**
214     * Returns a loggable value using pseudo-SQL syntax.
215     */
216    @SuppressWarnings("boxing")
217    public static String loggedValue(Object value) {
218        if (value == null) {
219            return "NULL";
220        }
221        if (value instanceof String) {
222            String v = (String) value;
223            if (v.length() > DEBUG_MAX_STRING) {
224                v = v.substring(0, DEBUG_MAX_STRING) + "...(" + v.length() + " chars)...";
225            }
226            return "'" + v.replace("'", "''") + "'";
227        }
228        if (value instanceof Calendar) {
229            Calendar cal = (Calendar) value;
230            char sign;
231            int offset = cal.getTimeZone().getOffset(cal.getTimeInMillis()) / 60000;
232            if (offset < 0) {
233                offset = -offset;
234                sign = '-';
235            } else {
236                sign = '+';
237            }
238            return String.format("TIMESTAMP '%04d-%02d-%02dT%02d:%02d:%02d.%03d%c%02d:%02d'", cal.get(Calendar.YEAR), //
239                    cal.get(Calendar.MONTH) + 1, //
240                    cal.get(Calendar.DAY_OF_MONTH), //
241                    cal.get(Calendar.HOUR_OF_DAY), //
242                    cal.get(Calendar.MINUTE), //
243                    cal.get(Calendar.SECOND), //
244                    cal.get(Calendar.MILLISECOND), //
245                    sign, offset / 60, offset % 60);
246        }
247        if (value instanceof java.sql.Date) {
248            return "DATE '" + value.toString() + "'";
249        }
250        if (value instanceof Object[]) {
251            Object[] v = (Object[]) value;
252            StringBuilder b = new StringBuilder();
253            b.append('[');
254            for (int i = 0; i < v.length; i++) {
255                if (i > 0) {
256                    b.append(',');
257                    if (i > DEBUG_MAX_ARRAY) {
258                        b.append("...(").append(v.length).append(" items)...");
259                        break;
260                    }
261                }
262                b.append(loggedValue(v[i]));
263            }
264            b.append(']');
265            return b.toString();
266        }
267        return value.toString();
268    }
269}