On 2012-05-09 17:12, Eugene Vigdorchik wrote:
> On Wed, May 9, 2012 at 4:14 PM, Stefan Zeiger<
szei...@googlemail.com> wrote:
>> On 2012-05-09 13:52, Stefan Zeiger wrote:
>>> I ran into another issue with forking: The test report in the end is
>>> wrong. If you look at the attached log, you'll see failure events for the
>>> following tests:
>>
>> Another issue: "logBuffered := false" seems to have no effect on forked test
>> runs. The output from the sbt logging and my replayed console output is
>> mixed up.
> I don't quite understand: isn't 'logBuffered := false' supposed to
> make logging immediate rather than buffered, so mix it with console
> output?
> However it's true that forking uses LoggedOutput to log everything
> that the subprocess writes to its stdout. Is it your problem?
Ah, you're right, it must be a different issue. I thought I needed
logBuffered := false but without forked tests, things works nicely
either way. I have junit-interface configured to buffer stdout and only
replay it if a test fails. Here's a sample output from a failed test
without forking:
[info] Test scala.slick.test.ql.UnionTest.testUnionWithoutProjection[0]
started
[Using test database jdbc:sqlite::memory:]
q: Union
left @1875208213: Wrapped
in: Filter
from @1387101257: [1] Table managers
where: Is
0: Wrapped
in: InRef @1387101257
value: <1>
what: RawNamedColumn name
1: ConstColumn[java.lang.String] Peter
what: <1>
right @154432519: Wrapped
in: Filter
from @
2075838214: <1>
where: Is
0: Wrapped
in: InRef @
2075838214
value: <1>
what: RawNamedColumn name
1: ConstColumn[java.lang.String] Amy
what: <1>
select * from (select a5."id", a5."name", a5."department" from
"managers" a5 where (a5."name"='Peter')) union (select a11."id", a11."name",
a11."department" from "managers" a11 where (a11."name"='Amy'))
[error] Test scala.slick.test.ql.UnionTest.testUnionWithoutProjection[0]
failed: [SQLITE_ERROR] SQL error or missing database (near "(": syntax
error)
[error] at org.sqlite.DB.newSQLException(DB.java:374)
[error] at org.sqlite.DB.newSQLException(DB.java:378)
[error] at org.sqlite.DB.throwex(DB.java:365)
[error] at org.sqlite.NestedDB.prepare(NestedDB.java:126)
[error] at org.sqlite.DB.prepare(DB.java:123)
[error] at org.sqlite.PrepStmt.this(PrepStmt.java:44)
[error] at org.sqlite.Conn.prepareStatement(Conn.java:403)
[error] at org.sqlite.Conn.prepareStatement(Conn.java:398)
[error] at
scala.slick.session.Session$class.prepareStatement(Session.scala:27)
[error] at
scala.slick.session.BaseSession.prepareStatement(Session.scala:94)
[error] at
scala.slick.jdbc.StatementInvoker.results(StatementInvoker.scala:29)
[error] at
scala.slick.jdbc.StatementInvoker.elementsTo(StatementInvoker.scala:17)
[error] at scala.slick.jdbc.Invoker$class.foreach(Invoker.scala:96)
[error] at
scala.slick.jdbc.StatementInvoker.foreach(StatementInvoker.scala:10)
[error] at scala.slick.jdbc.Invoker$class.build(Invoker.scala:65)
[error] at
scala.slick.jdbc.StatementInvoker.build(StatementInvoker.scala:10)
[error] at scala.slick.jdbc.Invoker$class.list(Invoker.scala:55)
[error] at
scala.slick.jdbc.StatementInvoker.list(StatementInvoker.scala:10)
[error] at scala.slick.jdbc.UnitInvoker$class.list(Invoker.scala:156)
[error] at
scala.slick.driver.BasicInvokerComponent$QueryInvoker.list(BasicInvokerComponent.scala:13)
[error] at
scala.slick.test.ql.UnionTest$$anonfun$testUnionWithoutProjection$1.apply$mcV$sp(UnionTest.scala:84)
[error] at
scala.slick.test.ql.UnionTest$$anonfun$testUnionWithoutProjection$1.apply(UnionTest.scala:71)
[error] at
scala.slick.test.ql.UnionTest$$anonfun$testUnionWithoutProjection$1.apply(UnionTest.scala:71)
[error] at
scala.util.DynamicVariable.withValue(DynamicVariable.scala:57)
[error] at
scala.slick.session.Database$$anonfun$withSession$1.apply(Database.scala:46)
[error] at
scala.slick.session.Database$$anonfun$withSession$1.apply(Database.scala:46)
[error] at scala.slick.session.Database.withSession(Database.scala:38)
[error] at scala.slick.session.Database.withSession(Database.scala:46)
[error] at
scala.slick.test.ql.UnionTest.testUnionWithoutProjection(UnionTest.scala:71)
[error] ...
[info] Test run finished: 2 failed, 0 ignored, 2 total, 0.155s
Stdout from the test goes directly to the console (not through the sbt
logger) and everything is nicely ordered (provided you set
parallelExecution in Test := false, of course, otherwise all bets are
off). With forked tests, I get something like this instead:
[info] Test scala.slick.test.ql.UnionTest.testUnionWithoutProjection[0]
started
[info] in: <8>
[info] what: RawNamedColumn name
[info] what: Wrapped
[info] in: <7>
[info] what: Wrapped
[info] in: <8>
[info] what: RawNamedColumn id
[info] 1: [9] Wrapped
[info] in: <4>
[info] what: Wrapped
[info] in: <7>
[info] what: Wrapped
[info] in: <8>
[info] what: RawNamedColumn name
[info] right @378689909: ProductNode
[info] 0: Wrapped
[info] in: [10] Bind
[info] from @1700966106: [11] Wrapped
[info] in: Filter
[info] from @835034678: [12] Table employees
[info] where: In
[info] 0: Wrapped
[info] in: InRef @835034678
[info] value: <12>
[info] what: RawNamedColumn manager
[info] 1: Bind
[info] from @622200001: [13] Wrapped
[info] in: Filter
[info] from @1217539564: <6>
[info] where: Is
[info] 0: Wrapped
[info] in: InRef @1217539564
[info] value: <6>
[info] what: RawNamedColumn department
[info] 1: ConstColumn[java.lang.String] IT
[info] what: <6>
[info] select: Pure
[info] value: Wrapped
[info] in: InRef @622200001
[info] value: <13>
[info] what: RawNamedColumn id
[info] what: <12>
[info] select: [14] Pure
[info] value: ProductNode
[info] 0: Wrapped
[info] in: [15] InRef @1700966106
[info] value: <11>
[info] what: RawNamedColumn id
[info] 1: Wrapped
[info] in: <15>
[info] what: RawNamedColumn name
[info] what: Wrapped
[info] in: <14>
[info] what: Wrapped
[info] in: <15>
[info] what: RawNamedColumn id
[info] 1: Wrapped
[info] in: <10>
[info] what: Wrapped
[info] in: <14>
[info] what: Wrapped
[info] in: <15>
[info] what: RawNamedColumn name
[info] what: <3>
[info] 1: [16] Wrapped
[info] in: <2>
[info] what: <9>
[info] select: Bind
[info] from @875322190: Wrapped
[info] in: OrderBy List((InRef
@1185181745,Ordering(Asc,NullsDefault)))
[info] from @1277065380: Pure
[info] value: ConstColumn[Unit] ()
[info] by0: [17] InRef @1185181745
[info] value: <16>
[info] what: Pure
[info] value: ConstColumn[Unit] ()
[info] select: Pure
[info] value: ProductNode
[info] 0: InRef @1185181745
[info] value: <1>
[info] 1: <17>
[info]
[info] Combined and sorted: select a1.a10, a1.a11 from (select * from
(select a6."id" as a10, a6."name" as a11 from "managers" a6 where
(a6."department"='IT')) union (select a14."id" as a10, a14."name" as a11
from "employees" a14 where (a14."manager" in (select a20."id" from
"managers" a20 where (a20."department"='IT'))))) a1 order by a1.a11
[info] [Using test database jdbc:sqlite::memory:]
[error] Test scala.slick.test.ql.UnionTest.testUnionWithoutProjection[0]
failed: [SQLITE_ERROR] SQL error or missing database (near "(": syntax
error)
[info] q: Union
[error] at org.sqlite.DB.newSQLException(DB.java:374)
[info] left @1329066519: Wrapped
[error] at org.sqlite.DB.newSQLException(DB.java:378)
[info] in: Filter
[error] at org.sqlite.DB.throwex(DB.java:365)
[info] from @438940141: [1] Table managers
[error] at org.sqlite.NativeDB.prepare(Native Method)
[info] where: Is
[error] at org.sqlite.DB.prepare(DB.java:123)
[info] 0: Wrapped
[error] at org.sqlite.PrepStmt.this(PrepStmt.java:44)
[info] in: InRef @438940141
[error] at org.sqlite.Conn.prepareStatement(Conn.java:403)
[info] value: <1>
[error] at org.sqlite.Conn.prepareStatement(Conn.java:398)
[info] what: RawNamedColumn name
[error] at
scala.slick.session.Session$class.prepareStatement(Session.scala:27)
[info] 1: ConstColumn[java.lang.String] Peter
[error] at
scala.slick.session.BaseSession.prepareStatement(Session.scala:94)
[info] what: <1>
[error] at
scala.slick.jdbc.StatementInvoker.results(StatementInvoker.scala:29)
[info] right @1643572386: Wrapped
[error] at
scala.slick.jdbc.StatementInvoker.elementsTo(StatementInvoker.scala:17)
[info] in: Filter
[error] at scala.slick.jdbc.Invoker$class.foreach(Invoker.scala:96)
[info] from @660622342: <1>
[error] at
scala.slick.jdbc.StatementInvoker.foreach(StatementInvoker.scala:10)
[info] where: Is
[error] at scala.slick.jdbc.Invoker$class.build(Invoker.scala:65)
[info] 0: Wrapped
[error] at
scala.slick.jdbc.StatementInvoker.build(StatementInvoker.scala:10)
[info] in: InRef @660622342
[error] at scala.slick.jdbc.Invoker$class.list(Invoker.scala:55)
[info] value: <1>
[error] at
scala.slick.jdbc.StatementInvoker.list(StatementInvoker.scala:10)
[info] what: RawNamedColumn name
[error] at scala.slick.jdbc.UnitInvoker$class.list(Invoker.scala:156)
[info] 1: ConstColumn[java.lang.String] Amy
[error] at
scala.slick.driver.BasicInvokerComponent$QueryInvoker.list(BasicInvokerComponent.scala:13)
[info] what: <1>
[error] at
scala.slick.test.ql.UnionTest$$anonfun$testUnionWithoutProjection$1.apply$mcV$sp(UnionTest.scala:84)
[info] select * from (select a5."id", a5."name", a5."department" from
"managers" a5 where (a5."name"='Peter')) union (select a11."id",
a11."name", a11."department" from "managers" a11 where (a11."name"='Amy'))
[error] at
scala.slick.test.ql.UnionTest$$anonfun$testUnionWithoutProjection$1.apply(UnionTest.scala:71)
[error] at
scala.slick.test.ql.UnionTest$$anonfun$testUnionWithoutProjection$1.apply(UnionTest.scala:71)
[error] at
scala.util.DynamicVariable.withValue(DynamicVariable.scala:57)
[error] at
scala.slick.session.Database$$anonfun$withSession$1.apply(Database.scala:46)
[error] at
scala.slick.session.Database$$anonfun$withSession$1.apply(Database.scala:46)
[error] at scala.slick.session.Database.withSession(Database.scala:38)
[error] at scala.slick.session.Database.withSession(Database.scala:46)
[error] at
scala.slick.test.ql.UnionTest.testUnionWithoutProjection(UnionTest.scala:71)
[error] ...
[info] Test run finished: 2 failed, 0 ignored, 2 total, 1.303s
All output goes through sbt's logger and it's all mixed up, even between
different tests. Maybe it's not executing them serially?