Hi Guys,
I have been testing 1.1.2 against a production system of ours with
approx 2160 users in an ldap repository.
It works well. But when I execute a reconciliation task I hit some
issues even although the reconciliation succeeds.
However I dont get a nice report of reconciliation as before.
As far as I can work out this is due to the number of users in the
reconcile syncope db.
Some traces:
on a system with few users (10's) I get a meaningful output (which is
accessed in the console):
mysql> select * from TaskExec;
:
<trimmed for brevity>
:
Roles deleted:
| 2013-10-08 13:24:04 | SUCCESS | 100 |
| 371 | 2013-10-08 13:25:09 | Users [created/failures]: 0/0
[updated/failures]: 17/0 [deleted/failures]: 0/0
Roles [created/failures]: 0/0 [updated/failures]: 13/0
[deleted/failures]: 0/0
Users created:
Users updated:
UPDATE SUCCESS (id/name): 150/root
UPDATE SUCCESS (id/name): 151/user
UPDATE SUCCESS (id/name): 200/babar
UPDATE SUCCESS (id/name): 201/babar2
UPDATE SUCCESS (id/name): 202/babar22
UPDATE SUCCESS (id/name): 203/babar23
UPDATE SUCCESS (id/name): 250/scanner
UPDATE SUCCESS (id/name): 251/[email protected]
UPDATE SUCCESS (id/name): 252/[email protected]
UPDATE SUCCESS (id/name): 253/[email protected]
UPDATE SUCCESS (id/name): 254/[email protected]
UPDATE SUCCESS (id/name): 255/[email protected]
UPDATE SUCCESS (id/name): 256/[email protected]
UPDATE SUCCESS (id/name): 257/[email protected]
UPDATE SUCCESS (id/name): 258/[email protected]
UPDATE SUCCESS (id/name): 259/[email protected]
UPDATE SUCCESS (id/name): 300/totorr
Users deleted:
Roles created:
Roles updated:
UPDATE SUCCESS (id/name): 200/consumer
UPDATE SUCCESS (id/name): 201/designer
UPDATE SUCCESS (id/name): 202/migrator
UPDATE SUCCESS (id/name): 203/admin
UPDATE SUCCESS (id/name): 204/starter
UPDATE SUCCESS (id/name): 205/partner
UPDATE SUCCESS (id/name): 206/plus
UPDATE SUCCESS (id/name): 207/team
UPDATE SUCCESS (id/name): 208/superuser
UPDATE SUCCESS (id/name): 209/root
UPDATE SUCCESS (id/name): 210/studiouser
UPDATE SUCCESS (id/name): 211/apiuser
UPDATE SUCCESS (id/name): 250/plug
Roles deleted:
| 2013-10-08 13:25:03 | SUCCESS | 100 |
+-----+---------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------+---------+---------+
44 rows in set (0.00 sec)
On the system with 1000's of usersI get no extra output other than
success of the task execution (nothing is reported in the console)
exit
mysql> select * from TaskExec;
+-----+---------------------+---------+---------------------+---------+---------+
| id | endDate | message | startDate | status | TASK_ID |
+-----+---------------------+---------+---------------------+---------+---------+
| 160 | 2013-10-08 08:36:43 | NULL | 2013-10-08 08:36:43 | SUCCESS
| 250 |
| 161 | 2013-10-08 08:36:44 | NULL | 2013-10-08 08:36:44 | SUCCESS
| 251 |
| 162 | 2013-10-08 08:36:44 | NULL | 2013-10-08 08:36:44 | SUCCESS
| 252 |
| 163 | 2013-10-08 08:36:45 | NULL | 2013-10-08 08:36:45 | SUCCESS
| 253 |
| 164 | 2013-10-08 08:36:45 | NULL | 2013-10-08 08:36:45 | SUCCESS
| 254 |
| 165 | 2013-10-08 08:36:45 | NULL | 2013-10-08 08:36:45 | SUCCESS
| 255 |
| 166 | 2013-10-08 08:36:46 | NULL | 2013-10-08 08:36:46 | SUCCESS
| 256 |
| 167 | 2013-10-08 08:36:46 | NULL | 2013-10-08 08:36:46 | SUCCESS
| 257 |
| 168 | 2013-10-08 08:36:46 | NULL | 2013-10-08 08:36:46 | SUCCESS
| 258 |
| 170 | 2013-10-08 08:43:26 | NULL | 2013-10-08 08:43:26 | SUCCESS
| 259 |
| 171 | 2013-10-08 08:43:27 | NULL | 2013-10-08 08:43:27 | SUCCESS
| 260 |
| 172 | 2013-10-08 08:43:27 | NULL | 2013-10-08 08:43:27 | SUCCESS
| 261 |
| 173 | 2013-10-08 08:43:27 | NULL | 2013-10-08 08:43:27 | SUCCESS
| 262 |
| 174 | 2013-10-08 08:43:27 | NULL | 2013-10-08 08:43:27 | SUCCESS
| 263 |
| 175 | 2013-10-08 08:43:28 | NULL | 2013-10-08 08:43:28 | SUCCESS
| 264 |
| 176 | 2013-10-08 08:43:28 | NULL | 2013-10-08 08:43:28 | SUCCESS
| 265 |
| 177 | 2013-10-08 08:43:28 | NULL | 2013-10-08 08:43:28 | SUCCESS
| 266 |
| 178 | 2013-10-08 08:43:28 | NULL | 2013-10-08 08:43:28 | SUCCESS
| 267 |
| 179 | 2013-10-08 08:43:29 | NULL | 2013-10-08 08:43:29 | SUCCESS
| 268 |
| 180 | 2013-10-08 08:43:29 | NULL | 2013-10-08 08:43:29 | SUCCESS
| 269 |
| 181 | 2013-10-08 08:43:29 | NULL | 2013-10-08 08:43:29 | SUCCESS
| 270 |
| 182 | 2013-10-08 08:43:29 | NULL | 2013-10-08 08:43:29 | SUCCESS
| 271 |
| 183 | 2013-10-08 08:43:29 | NULL | 2013-10-08 08:43:29 | SUCCESS
| 272 |
| 184 | 2013-10-08 08:43:30 | NULL | 2013-10-08 08:43:30 | SUCCESS
| 273 |
| 185 | 2013-10-08 08:43:30 | NULL | 2013-10-08 08:43:30 | SUCCESS
| 274 |
| 186 | 2013-10-08 08:43:30 | NULL | 2013-10-08 08:43:30 | SUCCESS
| 275 |
| 187 | 2013-10-08 08:43:31 | NULL | 2013-10-08 08:43:31 | SUCCESS
| 276 |
| 188 | 2013-10-08 08:45:47 | NULL | 2013-10-08 08:45:47 | SUCCESS
| 277 |
| 189 | 2013-10-08 08:45:47 | NULL | 2013-10-08 08:45:47 | SUCCESS
| 278 |
| 190 | 2013-10-08 08:45:48 | NULL | 2013-10-08 08:45:48 | SUCCESS
| 279 |
| 191 | 2013-10-08 08:45:48 | NULL | 2013-10-08 08:45:48 | SUCCESS
| 280 |
| 192 | 2013-10-08 08:45:48 | NULL | 2013-10-08 08:45:48 | SUCCESS
| 281 |
| 193 | 2013-10-08 08:45:48 | NULL | 2013-10-08 08:45:48 | SUCCESS
| 282 |
| 194 | 2013-10-08 08:45:49 | NULL | 2013-10-08 08:45:49 | SUCCESS
| 283 |
| 195 | 2013-10-08 08:45:49 | NULL | 2013-10-08 08:45:49 | SUCCESS
| 284 |
| 196 | 2013-10-08 08:45:49 | NULL | 2013-10-08 08:45:49 | SUCCESS
| 285 |
| 197 | 2013-10-08 08:45:49 | NULL | 2013-10-08 08:45:49 | SUCCESS
| 286 |
| 198 | 2013-10-08 08:45:50 | NULL | 2013-10-08 08:45:50 | SUCCESS
| 287 |
| 199 | 2013-10-08 08:45:50 | NULL | 2013-10-08 08:45:50 | SUCCESS
| 288 |
| 200 | 2013-10-08 08:45:50 | NULL | 2013-10-08 08:45:50 | SUCCESS
| 289 |
| 201 | 2013-10-08 08:45:50 | NULL | 2013-10-08 08:45:50 | SUCCESS
| 290 |
| 202 | 2013-10-08 08:45:50 | NULL | 2013-10-08 08:45:50 | SUCCESS
| 291 |
| 203 | 2013-10-08 08:45:51 | NULL | 2013-10-08 08:45:51 | SUCCESS
| 292 |
| 204 | 2013-10-08 08:45:51 | NULL | 2013-10-08 08:45:51 | SUCCESS
| 293 |
| 205 | 2013-10-08 08:45:51 | NULL | 2013-10-08 08:45:51 | SUCCESS
| 294 |
| 206 | 2013-10-08 08:47:56 | NULL | 2013-10-08 08:47:56 | SUCCESS
| 295 |
| 207 | 2013-10-08 08:47:57 | NULL | 2013-10-08 08:47:56 | SUCCESS
| 296 |
| 208 | 2013-10-08 08:47:57 | NULL | 2013-10-08 08:47:57 | SUCCESS
| 297 |
| 209 | 2013-10-08 08:47:57 | NULL | 2013-10-08 08:47:57 | SUCCESS
| 298 |
| 210 | 2013-10-08 08:47:57 | NULL | 2013-10-08 08:47:57 | SUCCESS
| 299 |
| 211 | 2013-10-08 08:47:57 | NULL | 2013-10-08 08:47:57 | SUCCESS
| 300 |
| 212 | 2013-10-08 08:47:58 | NULL | 2013-10-08 08:47:58 | SUCCESS
| 301 |
| 213 | 2013-10-08 08:47:58 | NULL | 2013-10-08 08:47:58 | SUCCESS
| 302 |
| 214 | 2013-10-08 08:47:58 | NULL | 2013-10-08 08:47:58 | SUCCESS
| 303 |
| 215 | 2013-10-08 08:47:58 | NULL | 2013-10-08 08:47:58 | SUCCESS
| 304 |
| 216 | 2013-10-08 08:47:58 | NULL | 2013-10-08 08:47:58 | SUCCESS
| 305 |
| 217 | 2013-10-08 08:47:59 | NULL | 2013-10-08 08:47:59 | SUCCESS
| 306 |
| 218 | 2013-10-08 08:47:59 | NULL | 2013-10-08 08:47:59 | SUCCESS
| 307 |
| 219 | 2013-10-08 08:47:59 | NULL | 2013-10-08 08:47:59 | SUCCESS
| 308 |
| 220 | 2013-10-08 08:47:59 | NULL | 2013-10-08 08:47:59 | SUCCESS
| 309 |
| 221 | 2013-10-08 08:47:59 | NULL | 2013-10-08 08:47:59 | SUCCESS
| 310 |
| 222 | 2013-10-08 08:48:00 | NULL | 2013-10-08 08:48:00 | SUCCESS
| 311 |
| 223 | 2013-10-08 08:48:00 | NULL | 2013-10-08 08:48:00 | SUCCESS
| 312 |
| 224 | 2013-10-08 09:06:53 | NULL | 2013-10-08 09:06:53 | SUCCESS
| 313 |
| 225 | 2013-10-08 09:06:53 | NULL | 2013-10-08 09:06:53 | SUCCESS
| 314 |
| 226 | 2013-10-08 09:06:53 | NULL | 2013-10-08 09:06:53 | SUCCESS
| 315 |
| 227 | 2013-10-08 09:06:53 | NULL | 2013-10-08 09:06:53 | SUCCESS
| 316 |
| 228 | 2013-10-08 09:06:54 | NULL | 2013-10-08 09:06:54 | SUCCESS
| 317 |
| 229 | 2013-10-08 09:06:54 | NULL | 2013-10-08 09:06:54 | SUCCESS
| 318 |
| 230 | 2013-10-08 09:06:54 | NULL | 2013-10-08 09:06:54 | SUCCESS
| 319 |
| 231 | 2013-10-08 09:06:54 | NULL | 2013-10-08 09:06:54 | SUCCESS
| 320 |
| 232 | 2013-10-08 09:06:54 | NULL | 2013-10-08 09:06:54 | SUCCESS
| 321 |
| 233 | 2013-10-08 09:06:55 | NULL | 2013-10-08 09:06:55 | SUCCESS
| 322 |
| 234 | 2013-10-08 09:06:55 | NULL | 2013-10-08 09:06:55 | SUCCESS
| 323 |
| 235 | 2013-10-08 09:06:55 | NULL | 2013-10-08 09:06:55 | SUCCESS
| 324 |
| 236 | 2013-10-08 09:06:55 | NULL | 2013-10-08 09:06:55 | SUCCESS
| 325 |
| 237 | 2013-10-08 09:06:55 | NULL | 2013-10-08 09:06:55 | SUCCESS
| 326 |
| 238 | 2013-10-08 09:06:56 | NULL | 2013-10-08 09:06:56 | SUCCESS
| 327 |
| 239 | 2013-10-08 09:06:56 | NULL | 2013-10-08 09:06:56 | SUCCESS
| 328 |
| 240 | 2013-10-08 09:06:56 | NULL | 2013-10-08 09:06:56 | SUCCESS
| 329 |
| 241 | 2013-10-08 09:06:56 | NULL | 2013-10-08 09:06:56 | SUCCESS
| 330 |
| 242 | 2013-10-08 09:12:10 | NULL | 2013-10-08 09:12:10 | SUCCESS
| 331 |
| 243 | 2013-10-08 09:12:10 | NULL | 2013-10-08 09:12:10 | SUCCESS
| 332 |
| 244 | 2013-10-08 09:12:10 | NULL | 2013-10-08 09:12:10 | SUCCESS
| 333 |
| 245 | 2013-10-08 09:12:10 | NULL | 2013-10-08 09:12:10 | SUCCESS
| 334 |
| 246 | 2013-10-08 09:12:11 | NULL | 2013-10-08 09:12:11 | SUCCESS
| 335 |
| 247 | 2013-10-08 09:12:11 | NULL | 2013-10-08 09:12:11 | SUCCESS
| 336 |
| 248 | 2013-10-08 09:12:11 | NULL | 2013-10-08 09:12:11 | SUCCESS
| 337 |
| 249 | 2013-10-08 09:12:11 | NULL | 2013-10-08 09:12:11 | SUCCESS
| 338 |
| 250 | 2013-10-08 09:12:12 | NULL | 2013-10-08 09:12:12 | SUCCESS
| 339 |
| 251 | 2013-10-08 09:12:12 | NULL | 2013-10-08 09:12:12 | SUCCESS
| 340 |
| 252 | 2013-10-08 09:12:12 | NULL | 2013-10-08 09:12:12 | SUCCESS
| 341 |
| 253 | 2013-10-08 09:12:12 | NULL | 2013-10-08 09:12:12 | SUCCESS
| 342 |
| 254 | 2013-10-08 09:12:13 | NULL | 2013-10-08 09:12:13 | SUCCESS
| 343 |
| 255 | 2013-10-08 09:12:13 | NULL | 2013-10-08 09:12:13 | SUCCESS
| 344 |
| 256 | 2013-10-08 09:12:13 | NULL | 2013-10-08 09:12:13 | SUCCESS
| 345 |
| 257 | 2013-10-08 09:12:14 | NULL | 2013-10-08 09:12:14 | SUCCESS
| 346 |
| 258 | 2013-10-08 09:12:14 | NULL | 2013-10-08 09:12:14 | SUCCESS
| 347 |
| 259 | 2013-10-08 09:12:14 | NULL | 2013-10-08 09:12:14 | SUCCESS
| 348 |
+-----+---------------------+---------+---------------------+---------+---------+
99 rows in set (0.00 sec)
mysql>
I see lots of issues in core.log:
i.e.
Caused by: org.apache.openjpa.persistence.PersistenceException: Data
truncation: Data too long for column 'message' at row 1 {prepstmnt
1398507577 INSERT INTO TaskExec (id, endDate, message, startDate,
status, TASK_ID) VALUES (?, ?, ?, ?, ?, ?)} [code=1406, state=22001]
at
org.apache.openjpa.jdbc.sql.DBDictionary.narrow(DBDictionary.java:4962)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.sql.DBDictionary.newStoreException(DBDictionary.java:4922)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:136)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.sql.SQLExceptions.getStore(SQLExceptions.java:78) ~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushAndUpdate(PreparedStatementManagerImpl.java:144)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.BatchingPreparedStatementManagerImpl.flushAndUpdate(BatchingPreparedStatementManagerImpl.java:79)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushInternal(PreparedStatementManagerImpl.java:100)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flush(PreparedStatementManagerImpl.java:88)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.ConstraintUpdateManager.flush(ConstraintUpdateManager.java:550)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.ConstraintUpdateManager.flush(ConstraintUpdateManager.java:106)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.BatchingConstraintUpdateManager.flush(BatchingConstraintUpdateManager.java:59)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdateManager.java:105)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.AbstractUpdateManager.flush(AbstractUpdateManager.java:78)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.JDBCStoreManager.flush(JDBCStoreManager.java:732)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.kernel.DelegatingStoreManager.flush(DelegatingStoreManager.java:131)
~[openjpa-kernel-2.2.2.jar:2.2.2]
at
org.apache.openjpa.datacache.DataCacheStoreManager.flush(DataCacheStoreManager.java:661)
~[openjpa-kernel-2.2.2.jar:2.2.2]
at
org.apache.openjpa.kernel.DelegatingStoreManager.flush(DelegatingStoreManager.java:131)
~[openjpa-kernel-2.2.2.jar:2.2.2]
... 21 common frames omitted
Caused by: org.apache.openjpa.lib.jdbc.ReportingSQLException: Data
truncation: Data too long for column 'message' at row 1 {prepstmnt
1398507577 INSERT INTO TaskExec (id, endDate, message, startDate,
status, TASK_ID) VALUES (?, ?, ?, ?, ?, ?)} [code=1406, state=22001]
at
org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.wrap(LoggingConnectionDecorator.java:219)
~[openjpa-lib-2.2.2.jar:2.2.2]
at
org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.wrap(LoggingConnectionDecorator.java:195)
~[openjpa-lib-2.2.2.jar:2.2.2]
at
org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator.access$1000(LoggingConnectionDecorator.java:59)
~[openjpa-lib-2.2.2.jar:2.2.2]
at
org.apache.openjpa.lib.jdbc.LoggingConnectionDecorator$LoggingConnection$LoggingPreparedStatement.executeUpdate(LoggingConnectionDecorator.java:1134)
~[openjpa-lib-2.2.2.jar:2.2.2]
at
org.apache.openjpa.lib.jdbc.DelegatingPreparedStatement.executeUpdate(DelegatingPreparedStatement.java:275)
~[openjpa-lib-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.JDBCStoreManager$CancelPreparedStatement.executeUpdate(JDBCStoreManager.java:1792)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.executeUpdate(PreparedStatementManagerImpl.java:268)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
at
org.apache.openjpa.jdbc.kernel.PreparedStatementManagerImpl.flushAndUpdate(PreparedStatementManagerImpl.java:119)
~[openjpa-jdbc-2.2.2.jar:2.2.2]
... 33 common frames omitted
08:18:53.621 ERROR org.quartz.core.ErrorLogger - Job (DEFAULT.taskJob100
threw an exception.
org.quartz.SchedulerException: Job threw an unhandled exception.
at org.quartz.core.JobRunShell.run(JobRunShell.java:224)
~[quartz-2.1.7.jar:na]
at
org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:557)
~[quartz-2.1.7.jar:na]
Caused by: org.springframework.orm.jpa.JpaSystemException: The
transaction has been rolled back. See the nested exceptions for details
on the errors that occurred.; nested exception is
<openjpa-2.2.2-r422266:1468616 fatal general error>
org.apache.openjpa.persistence.PersistenceException: The transaction has
been rolled back. See the nested exceptions for details on the errors
that occurred.
FailedObject: org.apache.syncope.core.persistence.beans.TaskExec@3455d699
My question is, is this a bug (if yes, maybe it is already fixed in
later versions)?
rgds,
Nik
