úterý 12. září 2017

Experiments with the Payara Micro, level I

New company, new project, new technologies. Okay, I'm experimenting with Payara Micro. Payara team produces more and more examples in several blogs, but they are very trivial and not always usable in production environment. At this time I'm not sure if I would be able to do the evolution to the final professional system, but it is not a problem, because the application modules are simply Java EE standard modules.
The difference is only in final organisation of the modules, deployment and container configuration, so I can create the standard EAR application in parallel to UBER jar with the Payara Micro. So this style of development is perfectly safe.

Target 

Application with the following modules:
  • DAO and bussines logic service module (JPA, JTA, EJB, CDI?), created but nearly empty in this blog 
  • Web service module (JAX-RS), only one simple service method in this blog 
  • GUI module (JSF), not resolved in this blog 
And project will have also following aggregation alternatives:
  • Uber JAR with Payara Micro - experimental, responsive development 
  • EAR for standard Payara domain 
The reason for this separation of modules is that a JSF GUI application obviously have different requirements than a Web service application. It might not be a problem for some time, but it could be a problem later. This is not any premature optimization - this will force developers to keep in mind the separation line between modules and maybe to create some clean API. That will help right now and it will be simplier to split it later.

There may be even more Maven modules:
  • superpom - common Maven plugin configurations, basic dependency management 
  • project parent - aggregator of all project modules 
  • integration tests for the web service module 
  • selenium tests for the gui module

Dead-end streets and good streets 

Well, I had hard two days with the Payara Micro. Blogs helped, but I always needed more and I was always stucked in some weird state. Yes, it was always my fault, but ... okay, now you can learn from my mistakes.

LOG4J2 

I used LOG4J with SLF4J for many years, it was pretty trivial to make it work and a bit harder to grab logs of embedded Payara in integration tests. I have found a memory leak in old LOG4J's reconfiguration and I know perhaps everything about that.
Now it is worthless with LOG4J2. But finally the configuration was also simple despite I still have not found a way to merge logs of the application and Payara. Example log4j2.properties, seems like a good street:
status = info
dest = err
name = PropertiesConfig
#log4j2.debug = true

property.path = target/logs

filter.threshold.type = ThresholdFilter
filter.threshold.level = debug

appender.console.type = Console
appender.console.name = STDOUT
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %m%n
appender.console.filter.threshold.type = ThresholdFilter
appender.console.filter.threshold.level = info

appender.rolling.type = RollingFile
appender.rolling.name = RollingFile
appender.rolling.fileName = ${path}/metering2-ws.log
appender.rolling.filePattern = ${path}/metering2-ws-%d{MM-dd-yy-HH-mm-ss}-%i.log.gz
appender.rolling.layout.type = PatternLayout
appender.rolling.layout.pattern = %d %p %C{2.} [%t] %m%n
appender.rolling.policies.type = Policies
appender.rolling.policies.time.type = TimeBasedTriggeringPolicy
appender.rolling.policies.time.interval = 2
appender.rolling.policies.time.modulate = true
appender.rolling.policies.size.type = SizeBasedTriggeringPolicy
appender.rolling.policies.size.size=1024MB
appender.rolling.strategy.type = DefaultRolloverStrategy
appender.rolling.strategy.max = 1

logger.ws.name = cz.x
logger.ws.level = debug
logger.ws.additivity = false
logger.ws.appenderRef.file.ref = RollingFile

rootLogger.level = debug
rootLogger.appenderRef.stdout.ref = STDOUT
rootLogger.appenderRef.file.ref = RollingFile  

JAX-RS, lists ... Jackson!

Creating the first JAX-RS web service is pretty trivial ... you need two classes, first to configure the context of services in the module, second to implement the service:

import javax.ws.rs.ApplicationPath;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;
import org.glassfish.jersey.server.ResourceConfig;

@ApplicationPath("rs")
public class RestAppConfig extends ResourceConfig {

  private static final Logger LOG = LogManager.getLogger(RestAppConfig.class);

  public RestAppConfig() {
    LOG.debug("RestAppConfig()");
    try {
      packages(RestAppConfig.class.getPackage().getName());
      LOG.info("REST configured!");
    } catch (final Exception e) {
      LOG.error("Cannot configure the REST web services!", e);
    }
  }
}
And the second:

import java.util.Arrays;
import java.util.List;
import javax.ws.rs.GET;
import javax.ws.rs.Path;
import javax.ws.rs.Produces;
import javax.ws.rs.core.MediaType;
import javax.ws.rs.core.Response;

@Path("user")
public class UserRestService {

  @GET
  @Path("list")
  @Produces(MediaType.APPLICATION_JSON)
  public Response list() {
    final List<String> list = Arrays.asList("Křemílek", "Vochomůrka"); // UTFG ;-)
    return Response.ok(list).build();
  }
} 
Maven command to run the application, it will be used in all following examples:
 mvn clean install;  mvn fish.payara.maven.plugins:payara-micro-maven-plugin:start -pl :metering2-uberjar
Final part of the log:

[2017-09-12T16:31:25.369+0200] [] [INFO] [AS-WEB-GLUE-00172] [javax.enterprise.web] [tid: _ThreadID=1 _ThreadName=main] [timeMillis: 1505226685369] [levelValue: 800] Loading application [metering2-ws-0.0.1-SNAPSHOT] at [/metering2-ws-0.0.1-SNAPSHOT]

[2017-09-12T16:31:25.681+0200] [] [INFO] [] [javax.enterprise.system.core] [tid: _ThreadID=1 _ThreadName=main] [timeMillis: 1505226685681] [levelValue: 800] metering2-ws-0.0.1-SNAPSHOT was successfully deployed in 12 472 milliseconds.

[2017-09-12T16:31:25.685+0200] [] [INFO] [] [PayaraMicro] [tid: _ThreadID=1 _ThreadName=main] [timeMillis: 1505226685685] [levelValue: 800] Deployed 1 archive(s)

[2017-09-12T16:31:25.686+0200] [] [INFO] [] [PayaraMicro] [tid: _ThreadID=1 _ThreadName=main] [timeMillis: 1505226685686] [levelValue: 800] [[
 
Instance Configuration
Host: dmatej-lenovo
HTTP Port(s): 8080
HTTPS Port(s):
Instance Name: Frail-Barracuda
Instance Group: MicroShoal
Hazelcast Member UUID cbddb9aa-5f21-4ee1-984f-78be942124d4
Deployed: metering2-ws-0.0.1-SNAPSHOT ( metering2-ws-0.0.1-SNAPSHOT war /metering2-ws-0.0.1-SNAPSHOT )

]]

[2017-09-12T16:31:25.702+0200] [] [INFO] [] [PayaraMicro] [tid: _ThreadID=1 _ThreadName=main] [timeMillis: 1505226685702] [levelValue: 800] [[
 
Payara Micro URLs
http://dmatej-lenovo:8080/metering2-ws-0.0.1-SNAPSHOT

'metering2-ws-0.0.1-SNAPSHOT' REST Endpoints
GET     /metering2-ws-0.0.1-SNAPSHOT/rs/user/list

]]
Ok, that was pretty simple. But the service does not work and ends up with HTTP 500 (try it with browser):

[2017-09-12T20:19:02.013+0200] [] [SEVERE] [] [org.glassfish.jersey.message.internal.WriterInterceptorExecutor] [tid: _ThreadID=22 _ThreadName=http-thread-pool::http-listener(3)] [timeMillis: 1505240342013] [levelValue: 1000] MessageBodyWriter not found for media type=application/json, type=class java.util.Arrays$ArrayList, genericType=class java.util.Arrays$ArrayList.

Solution 

Only add the dependency on Jackson to pom.xml and the following line as the first to the RestAppConfig's constructor:
register(JacksonFeature.class);
The final pom.xml of the ws module:

 <project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
  <modelVersion>4.0.0</modelVersion>
  <artifactId>metering2-ws</artifactId>
  <packaging>war</packaging>
  <name>Metering2 prototype - Web Services</name>
  <parent>
    <groupId>cz.netpro.metering2</groupId>
    <artifactId>parent-pom</artifactId>
    <version>0.0.1-SNAPSHOT</version>
    <relativePath>..</relativePath>
  </parent>
  <dependencies>
    <dependency>
      <groupId>org.apache.logging.log4j</groupId>
      <artifactId>log4j-api</artifactId>
    </dependency>
    <dependency>
      <groupId>org.apache.logging.log4j</groupId>
      <artifactId>log4j-core</artifactId>
    </dependency>
    <dependency>
      <groupId>javax.ws.rs</groupId>
      <artifactId>javax.ws.rs-api</artifactId>
    </dependency>
    <dependency>
      <groupId>javax</groupId>
      <artifactId>javaee-api</artifactId>
    </dependency>
    <!-- to use optimized JAX-RS configuration -->
    <dependency>
      <groupId>org.glassfish.jersey.core</groupId>
      <artifactId>jersey-server</artifactId>
    </dependency>
    <!-- to simply use lists in JSONs -->
    <dependency>
      <groupId>org.glassfish.jersey.media</groupId>
      <artifactId>jersey-media-json-jackson</artifactId>
    </dependency>
  </dependencies>
  <build>
    <resources>
      <resource>
        <directory>src/main/resources</directory>
        <filtering>false</filtering>
        <includes>
          <include>**/*.properties</include>
        </includes>
      </resource>
    </resources>
  </build>
</project>

JDBC Pool 

This was a real pain but solution was so simple ... do you know what I hate? NullpointerException. In fact I appreciate that it exists, because it tells "the programmer was not careful". And if the programmer was not careful, it is a bug - maybe even trivial to fix. But another exception I have seen was ClassNotFoundException ... This is the pom.xml of the UBER jar:

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
  <modelVersion>4.0.0</modelVersion>
  <groupId>cz.netpro.metering2</groupId>
  <artifactId>metering2-uberjar</artifactId>
  <version>0.0.1-SNAPSHOT</version>
  <name>Metering2 Uberjar</name>
  <parent>
    <groupId>cz.netpro</groupId>
    <artifactId>superpom</artifactId>
    <version>0.0.1-SNAPSHOT</version>

  </parent>
  <build>
    <resources>
      <resource>
        <directory>src/main/resources</directory>
        <filtering>false</filtering>
        <includes>
          <include>**/*.txt</include>
        </includes>
      </resource>
    </resources>
    <plugins>
      <!-- HOWTO: https://github.com/payara/maven-plugins -->
      <plugin>
        <groupId>fish.payara.maven.plugins</groupId>
        <artifactId>payara-micro-maven-plugin</artifactId>
        <version>1.0.0</version>
        <executions>
          <execution>
            <goals>
              <goal>bundle</goal>
            </goals>
          </execution>
        </executions>
        <configuration>
          <payaraVersion>4.1.2.173</payaraVersion>
          <useUberJar>true</useUberJar>
          <deployArtifacts>
            <deployArtifact>
              <groupId>cz.netpro.metering2</groupId>
              <artifactId>metering2-ws</artifactId>
              <version>${project.version}</version>
              <type>war</type>
            </deployArtifact>
          </deployArtifacts>
          <customJars>
            <customJar>
              <groupId>org.apache.logging.log4j</groupId>
              <artifactId>log4j-api</artifactId>
            </customJar>
            <customJar>
              <groupId>org.apache.logging.log4j</groupId>
              <artifactId>log4j-core</artifactId>
            </customJar>
            <customJar>
              <groupId>mysql</groupId>
              <artifactId>mysql-connector-java</artifactId>
            </customJar>
          </customJars>
          <commandLineOptions>
            <commandLineOption>
              <key>--autobindhttp</key>
              <value>true</value>
            </commandLineOption>
            <commandLineOption>
              <key>--prebootcommandfile</key>
              <value>${project.build.outputDirectory}/prepare-resources.txt</value>
            </commandLineOption>
          </commandLineOptions>
        </configuration>
      </plugin>
    </plugins>
  </build>
</project>
The prepare-resources.txt was this (note that empty lines are interpreted as an error):

set configs.config.server-config.admin-service.das-config.dynamic-reload-enabled=false
set configs.config.server-config.admin-service.das-config.autodeploy-enabled=false
create-jdbc-connection-pool --datasourceclassname com.mysql.cj.jdbc.MysqlDataSource --restype javax.sql.DataSource --property user=test:password=test:DatabaseName=iqhouse_metering:ServerName=localhost:port=3306:zeroDateTimeBehavior=convertToNull:useUnicode=true:useJDBCCompliantTimezoneShift=true:useLegacyDatetimeCode=true:serverTimezone=UTC:characterEncoding=UTF-8 metering-mysql
set resources.jdbc-connection-pool.metering-mysql.steady-pool-size=5
set resources.jdbc-connection-pool.metering-mysql.max-pool-size=20
set resources.jdbc-connection-pool.metering-mysql.connection-validation-method=auto-commit
set resources.jdbc-connection-pool.metering-mysql.is-connection-validation-required=true
set resources.jdbc-connection-pool.metering-mysql.fail-all-connections=true
ping-connection-pool metering-mysql
But it did not work, server startup failed and I had no idea why ... and Payara did not help me ... there were two kind of stacktraces:

java.lang.RuntimeException: Orb initialization erorr
        at org.glassfish.enterprise.iiop.api.GlassFishORBHelper.getORB(GlassFishORBHelper.java:191)
        at com.sun.enterprise.naming.impl.SerialContext.getORB(SerialContext.java:349)
        at com.sun.enterprise.naming.impl.SerialContext.getProviderCacheKey(SerialContext.java:356)
        at com.sun.enterprise.naming.impl.SerialContext.getRemoteProvider(SerialContext.java:386)
        at com.sun.enterprise.naming.impl.SerialContext.getProvider(SerialContext.java:331)
        at com.sun.enterprise.naming.impl.SerialContext.lookup(SerialContext.java:480)
        at com.sun.enterprise.naming.impl.SerialContext.lookup(SerialContext.java:440)
        at javax.naming.InitialContext.lookup(InitialContext.java:417)
        at org.glassfish.resourcebase.resources.naming.ResourceNamingService.lookup(ResourceNamingService.java:236)
        at com.sun.enterprise.connectors.service.ConnectorConnectionPoolAdminServiceImpl.getConnectorConnectionPool(ConnectorConnectionPoolAdminServiceImpl.java:799)
        at com.sun.enterprise.connectors.service.ConnectorConnectionPoolAdminServiceImpl.obtainManagedConnectionFactory(ConnectorConnectionPoolAdminServiceImpl.java:938)
        at com.sun.enterprise.connectors.service.ConnectorConnectionPoolAdminServiceImpl.getUnpooledConnection(ConnectorConnectionPoolAdminServiceImpl.java:549)
        at com.sun.enterprise.connectors.service.ConnectorConnectionPoolAdminServiceImpl.testConnectionPool(ConnectorConnectionPoolAdminServiceImpl.java:430)
        at com.sun.enterprise.connectors.ConnectorRuntime.pingConnectionPool(ConnectorRuntime.java:1162)
        at org.glassfish.connectors.admin.cli.PingConnectionPool.execute(PingConnectionPool.java:143)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$2$1.run(CommandRunnerImpl.java:544)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$2$1.run(CommandRunnerImpl.java:540)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:360)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$2.execute(CommandRunnerImpl.java:539)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$3.run(CommandRunnerImpl.java:570)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$3.run(CommandRunnerImpl.java:562)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:360)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl.doCommand(CommandRunnerImpl.java:561)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl.doCommand(CommandRunnerImpl.java:1469)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl.access$1300(CommandRunnerImpl.java:111)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$ExecutionContext.execute(CommandRunnerImpl.java:1851)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$ExecutionContext.execute(CommandRunnerImpl.java:1727)
        at com.sun.enterprise.admin.cli.embeddable.CommandExecutorImpl.executeCommand(CommandExecutorImpl.java:169)
        at com.sun.enterprise.admin.cli.embeddable.CommandExecutorImpl.run(CommandExecutorImpl.java:94)
        at fish.payara.micro.boot.runtime.BootCommand.execute(BootCommand.java:65)
        at fish.payara.micro.boot.runtime.BootCommands.executeCommands(BootCommands.java:105)
        at fish.payara.micro.boot.runtime.BootCommands.executeCommands(BootCommands.java:99)
        at fish.payara.micro.impl.PayaraMicroImpl.bootStrap(PayaraMicroImpl.java:987)
        at fish.payara.micro.impl.PayaraMicroImpl.main(PayaraMicroImpl.java:186)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at fish.payara.micro.boot.loader.MainMethodRunner.run(MainMethodRunner.java:48)
        at fish.payara.micro.boot.loader.Launcher.launch(Launcher.java:107)
        at fish.payara.micro.boot.loader.Launcher.launch(Launcher.java:70)
        at fish.payara.micro.boot.PayaraMicroLauncher.main(PayaraMicroLauncher.java:79)
        at fish.payara.micro.PayaraMicro.main(PayaraMicro.java:361)
Caused by: java.lang.NullPointerException
        at org.glassfish.enterprise.iiop.api.GlassFishORBHelper.getORB(GlassFishORBHelper.java:163)
        ... 44 more
[2017-09-12T21:42:28.782+0200] [] [SEVERE] [] [javax.enterprise.resource.resourceadapter.com.sun.enterprise.connectors] [tid: _ThreadID=1 _ThreadName=main] [timeMillis: 1505245348782] [levelValue: 1000] RAR6001 : Class Not found : com.sun.gjc.spi.ResourceAdapterImpl


com.sun.appserv.connectors.internal.api.ConnectorRuntimeException: Error in creating active RAR
        at com.sun.enterprise.connectors.ActiveRAFactory.createActiveResourceAdapter(ActiveRAFactory.java:111)
        at com.sun.enterprise.connectors.service.ResourceAdapterAdminServiceImpl.createActiveResourceAdapter(ResourceAdapterAdminServiceImpl.java:212)
        at com.sun.enterprise.connectors.service.ResourceAdapterAdminServiceImpl.createActiveResourceAdapter(ResourceAdapterAdminServiceImpl.java:348)
        at com.sun.enterprise.connectors.ConnectorRuntime.createActiveResourceAdapter(ConnectorRuntime.java:405)
        at com.sun.enterprise.connectors.service.ConnectorService.loadDeferredResourceAdapter(ConnectorService.java:184)
        at com.sun.enterprise.connectors.service.ConnectorService.loadResourcesAndItsRar(ConnectorService.java:148)
        at com.sun.enterprise.connectors.service.ConnectorService.checkAndLoadPool(ConnectorService.java:325)
        at com.sun.enterprise.connectors.service.ConnectorConnectionPoolAdminServiceImpl.getUnpooledConnection(ConnectorConnectionPoolAdminServiceImpl.java:553)
        at com.sun.enterprise.connectors.service.ConnectorConnectionPoolAdminServiceImpl.testConnectionPool(ConnectorConnectionPoolAdminServiceImpl.java:430)
        at com.sun.enterprise.connectors.ConnectorRuntime.pingConnectionPool(ConnectorRuntime.java:1162)
        at org.glassfish.connectors.admin.cli.PingConnectionPool.execute(PingConnectionPool.java:143)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$2$1.run(CommandRunnerImpl.java:544)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$2$1.run(CommandRunnerImpl.java:540)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:360)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$2.execute(CommandRunnerImpl.java:539)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$3.run(CommandRunnerImpl.java:570)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$3.run(CommandRunnerImpl.java:562)
        at java.security.AccessController.doPrivileged(Native Method)
        at javax.security.auth.Subject.doAs(Subject.java:360)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl.doCommand(CommandRunnerImpl.java:561)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl.doCommand(CommandRunnerImpl.java:1469)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl.access$1300(CommandRunnerImpl.java:111)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$ExecutionContext.execute(CommandRunnerImpl.java:1851)
        at com.sun.enterprise.v3.admin.CommandRunnerImpl$ExecutionContext.execute(CommandRunnerImpl.java:1727)
        at com.sun.enterprise.admin.cli.embeddable.CommandExecutorImpl.executeCommand(CommandExecutorImpl.java:169)
        at com.sun.enterprise.admin.cli.embeddable.CommandExecutorImpl.run(CommandExecutorImpl.java:94)
        at fish.payara.micro.boot.runtime.BootCommand.execute(BootCommand.java:65)
        at fish.payara.micro.boot.runtime.BootCommands.executeCommands(BootCommands.java:105)
        at fish.payara.micro.boot.runtime.BootCommands.executeCommands(BootCommands.java:99)
        at fish.payara.micro.impl.PayaraMicroImpl.bootStrap(PayaraMicroImpl.java:987)
        at fish.payara.micro.impl.PayaraMicroImpl.main(PayaraMicroImpl.java:186)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at fish.payara.micro.boot.loader.MainMethodRunner.run(MainMethodRunner.java:48)
        at fish.payara.micro.boot.loader.Launcher.launch(Launcher.java:107)
        at fish.payara.micro.boot.loader.Launcher.launch(Launcher.java:70)
        at fish.payara.micro.boot.PayaraMicroLauncher.main(PayaraMicroLauncher.java:79)
        at fish.payara.micro.PayaraMicro.main(PayaraMicro.java:361)
Caused by: java.lang.ClassNotFoundException: com.sun.gjc.spi.ResourceAdapterImpl
        at com.sun.enterprise.v3.server.APIClassLoaderServiceImpl$APIClassLoader.loadClass(APIClassLoaderServiceImpl.java:245)
        at com.sun.enterprise.v3.server.APIClassLoaderServiceImpl$APIClassLoader.loadClass(APIClassLoaderServiceImpl.java:237)
        at com.sun.enterprise.connectors.ActiveRAFactory.createActiveResourceAdapter(ActiveRAFactory.java:103)
        ... 40 more
]]

Dead-end street: comment out ping 

Okay, stacktraces are gone. But I don't know if the pool has been created and if it works.

Dead-end street: add dependencies 

Idea: add missing dependencies. The Payara versions are not in Maven Central, so I tried to add glassfish versions of org.glassfish.main.jdbc.jdbc-ra.jdbc-core:jdbc-core:4.1.2 and org.glassfish.main.jdbc.jdbc-ra.jdbc40:jdbc40:4.1.2 ... Result? Several warnings like this and finally exception. Dumb idea? Something similar helped us with old versions of the Embedded Payara started by JUnit integration tests but here it was only a cargo antipattern.

[2017-09-12T21:36:37.619+0200] [] [WARNING] [] [javax.enterprise.resource.resourceadapter.com.sun.enterprise.connectors.util] [tid: _ThreadID=1 _ThreadName=main] [timeMillis: 1505244997619] [levelValue: 900] RAR8000 : The method setLogJdbcCalls is not present in the class : com.sun.gjc.spi.DSManagedConnectionFactory

com.sun.appserv.connectors.internal.api.ConnectorRuntimeException: Failed to create MCF for metering-mysql
        at com.sun.enterprise.connectors.service.ConnectorConnectionPoolAdminServiceImpl.createConnectorConnectionPool(ConnectorConnectionPoolAdminServiceImpl.java:195)
        at com.sun.enterprise.connectors.ConnectorRuntime.createConnectorConnectionPool(ConnectorRuntime.java:331)
        at org.glassfish.jdbc.deployer.JdbcConnectionPoolDeployer.actualDeployResource(JdbcConnectionPoolDeployer.java:201)
        at org.glassfish.jdbc.deployer.JdbcConnectionPoolDeployer.deployResource(JdbcConnectionPoolDeployer.java:170)
        at com.sun.enterprise.connectors.service.ConnectorService.loadDeferredResources(ConnectorService.java:233)
        at com.sun.enterprise.connectors.service.ConnectorService$1.run(ConnectorService.java:153)
        at java.security.AccessController.doPrivileged(Native Method)
Those two dependencies now remove, they are not needed and more, they are not compatible.

Look into the Payara sources and think

 ... and create this issue: https://github.com/payara/Payara/issues/1967 Oh, by the way, why I did not think it before? ORB factory is simply initialized after the prebootcommandfile execution! Ok, let's move the ping to a new file postboot.txt and add another commandLineOption to pom.xml:
<commandLineOption>
  <key>--postbootcommandfile</key>
  <value>${project.build.outputDirectory}/postboot.txt</value>
</commandLineOption>

MySQL and time zones 

Pool ping was still failing with some weird error message about unknown CEST timezone. StackOverflow advices did not work, neither one about configuring the JDBC driver. I have found several bugs reported to MySQL devs: https://bugs.mysql.com/bug.php?id=86425
I tried to change the server's default-time-zone via the MySql Workbench with no success until I noted that it updates incorrect file in my user's home directory. Finally I added these lines into /etc/mysql/my.cnf and restarted the mysql service ... and it worked.
[mysqld]
default-time-zone = +00:00

Success 

Yes, that was all. But ... there is nothing interesting in the log output, no logging about asadmin commands, no logging about their success. I was lazy to create my own logging.properties and to add path as another commandLineOption so I hacked the jar in maven repository (please, don't do this, don't be lazy!) ... the nearest usable loggers and logs was these:

[2017-09-12T22:23:53.622+0200] [] [FINE] [] [javax.enterprise.resource.resourceadapter.org.glassfish.jdbcruntime] [tid: _ThreadID=1 _ThreadName=main] [timeMillis: 1505247833622] [levelValue: 500] [CLASSNAME: org.glassfish.jdbcruntime.JdbcRuntimeExtension] [METHODNAME: isConnectionPoolReferredInServerInstance] JDBC resource jdbc/metering2-jtarefers metering-mysqlin this server instance and is enabled
 

[2017-09-12T22:23:54.398+0200] [] [FINE] [] [org.glassfish.naming] [tid: _ThreadID=1 _ThreadName=main] [timeMillis: 1505247834398] [levelValue: 500] [CLASSNAME: com.sun.enterprise.naming.util.NamingUtilsImpl] [METHODNAME: makeCopyOfObject] [[
  ** makeCopyOfObject:: ConnectorConnectionPool :: metering-mysql
steady size: 5
max pool size: 20
max wait time: 60000
pool resize qty: 2
Idle timeout: 300
failAllConnections: true
Transaction Support Level: 1
isConnectionValidationRequired_ true
preferValidateOverRecreate_ false
matchConnections_ false
associateWithThread_ false
lazyConnectionAssoc_ false
lazyConnectionEnlist_ false
maxConnectionUsage_ 0
pingPoolDuringCreation_ false
poolingOn_ true
validateAtmostOncePeriod_ 0
connectionLeakTracingTimeout_0
connectionReclaim_false
connectionCreationRetryAttempts_0
connectionCreationRetryIntervalInMilliSeconds_10
nonTransactional_ false
nonComponent_ false
ConnectorDescriptorInfo ->
rarName: __ds_jdbc_ra
resource adapter class: com.sun.gjc.spi.ResourceAdapterImpl
connection def name: javax.sql.DataSource
MCF Config properties-> ClassName:com.mysql.cj.jdbc.MysqlDataSource
ConnectionValidationRequired:true
ValidationMethod:auto-commit
ValidationTableName:
ValidationClassName:
TransactionIsolation:
GuaranteeIsolationLevel:true
StatementWrapping:true
LogJdbcCalls:false
SlowQueryThresholdInSeconds:-1
StatementTimeout:-1
PoolMonitoringSubTreeRoot:resources/metering-mysql
PoolName:metering-mysql
StatementCacheSize:0
StatementCacheType:
InitSql:null
SqlTraceListeners:fish.payara.jdbc.SilentSqlTraceListener
StatementLeakTimeoutInSeconds:0
StatementLeakReclaim:false
DatabaseName:iqhouse_metering
User:test
Password:****
ServerName:localhost
DriverProperties:setcharacterEncoding#UTF-8##setport#3306##setuseJDBCCompliantTimezoneShift#true##setuseLegacyDatetimeCode#true##setuseUnicode#true##setserverTimezone#UTC##setzeroDateTimeBehavior#convertToNull##
Delimiter:#
EscapeCharacter:\
]]  
Now I can continue to level 2: JPA services ... to be continued ;)

pátek 21. července 2017

Manday není jednotka!

Tento příspěvek bude česky, protože se týká hlavně českých firem, tvořících software, a je podložen praxí, bohužel.

Pro některé je titulek možná šokující odhalení a děsný podraz, jelikož celý život krom jednotek Kč, EURO, hodina, den, týden a procento používali též "člověkoden" (manday) a "člověkohodinu" (manhour). O té poslední se zmiňovat ani nebudu, platí pro ní totéž, co pro tu v titulku.

Manday přece funguje

Ano, někdy funguje. Třeba při výkopových pracích bývá rozdíl mezi dělníky řádový jen výjimečně. Manažer si odhad pro jistotu vynásobí nějakým koeficientem a má skoro jistotu, že se termín stihne. Může dokonce jen s malou chybou počítat "cenu manday", atd.
Jenže my se bavíme o tvorbě software, kde jsou rozdíly mezi programátory, analytiky, testery i konzultanty obrovské.

Pepa není Franta

Máte velký projekt, který tvoří statisíce řádek kódu, dvacítka příruček, desetitisíce automatických testů, tisíce uživatelských scénářů pro akceptace a školení, za projektem jsou léta vývoje, používá se poměrně velká sada kompatibilních technologií s popsaným způsobem vazeb ...
Pepa je senior, projekt vede pět let, možná nerozumí všemu, ale přinejmenším ví, "že to tam je", a po deseti minutách se umí zorientovat. Franta je též senior, firma ho zrovna přijala, má léta praxe, všechny používané technologie "má v malíčku", má taky dvojnásobný plat než Pepa.

Stejný úkol

Přesto když ti dva dostanou stejný úkol, Pepa ho má do hodiny vyřešený, Franta pravděpodobně něco rozbije. Manažer se zlobí, začíná pochybovat o tom, že přijetí Franty bylo správné. Možná ho přeřadí na jiný projekt, kde se to zopakuje. Nebo to Frantu nechá opravit a dodělat, a rozčiluje se, že místo jednoho dne, který dostal s velkou rezervou, je to už týden.
První problém totiž je, že práce nováčka se nedá odhadovat bez ohledu na jeho léta praxe na jiných projektech.

Samouk

Další zlá varianta - tým má už tak málo lidí, že Pepa nemá čas na nováčka v týmu, každý den hasí "požáry". V rychlosti na něj každý den vychrlí nové informace, nemá čas ale vysvětlovat podrobnosti. Frantu hodí do vody, ukáže mu jak plavat, a dál ať to zkouší sám. Výsledek? Utekl měsíc, Franta je stále mimo, nefunguje mu už ani editor, nechápe proč. Nadává, co je tohle za firmu. Manažer vynadá Pepovi, ten ho nevrle pošle "do lesa".

Jinak a lépe

Nejefektivnější způsob zaučování je párové programování. Prostě si spolu musí aspoň na půlku pracovní doby sednout, Pepa bude navigátor, Franta řidič. Občas může být problém Frantovo ego, ale to už je na tom, jestli nový člen týmu zapadne do kolektivu. Samozřejmě mandays běží dvojnásobným tempem, ale čert je vem. Postupem času bude Pepy třeba méně a méně, při přechodu na další odlišnou práci si zase spolu sednou a dělají spolu.

Každý je nahraditelný ...?

Je? Není? Ale jo, je ... ale je třeba zvážit, za jakou cenu, přičemž cenou je tu hlavně čas (že čas nejsou peníze, vysvětlím dále). Někteří lidé prakticky nejsou v přijatelném časovém horizontu nahraditelní jedním člověkem - je třeba si rozmyslet, kolik a jaké práce běžně odváděli, v jaké kvalitě i kvantitě (to je další problém - jak to měřit?), a ideálně dostatečný počet nových lidí přibrat do týmu dříve než dotyčný odejde. I tak dojde ke zpoždění, protože je bude třeba do vývoje "dostat".

Opět - Pepa není ekvivalentem pěti Jindřichů ani padesáti Karlíků. Vyplnit vzniklou mezeru může být velmi těžké a pro celý tým stresující, čili je třeba, aby mezera byla co nejmenší, ideálně aby vznikl překryv. Pepa si nové lidi sám zaškolí.

Struktura týmu

V ČR je bohužel zažitá praxe, že organizace firem je hierarchická, někdy dokonce s mnoho patry. Kupodivu to většinou nefunguje, nebo to přinejmenším nefunguje hladce.
Druhý nešvarem je, že firmy týmy dimenzují spíše tak, že týmu jeden člověk chybí než aby jeden člověk přebýval. Tým pak nemá žádnou rezervu na řešení náhlých problémů, výzkum alternativ, atd. Tento přístup je přímo sebevražedný.

V týmu by měli být lidé sobě rovnocenní a měli by si rozdělit práci tak trochu podle vlastních preferencí a specializací. Projektový manažer nesmí být víc než vývojář ani naopak, oba by se měli ale vzájemně respektovat, oba jsou potřebnými a rovnocennými experty, každý na svou oblast.
V týmu si lidé musí vyměňovat názory, klidně se můžou i hádat, ale nesmí sebou navzájem pohrdat nebo se sebe bát v žádném smyslu slova.

Plánování práce

Předem píšu, že se stále bavíme o velkých zakázkách, řádově stovky až tisíce mandays.
Zákazník jen málokdy dodá kompletní specifikaci toho, co chce. Ve smlouvě je často jen název zakázky, cena. No a protože je třeba nějak specifikovat, za co že ta cena vlastně je, stanoví se nějaký počet mandays na základě velmi hrubé analýzy toho, co všechno bude obsahem zakázky.
Tato hodnota smí být užita nanejvýš orientačnímu porovnání s jinými zakázkami, a to ještě s velkou opatrností, nebo k orientačnímu rozdělení zakázky na fragmenty. Jinak je k ničemu a pokud jí k něčemu použijete, nedivte se, že vám pak nic nebude vycházet.

No dobře, když ale nemůžeme používat mandays, jak máme plánovat? Hned na začátku by měly být jasné dva údaje:
  • termín
  • rozpočet
A od nich a na základě nějakého interního rozboru analýzy odvodit strukturu týmu, jaký bude na implementaci nasazen, pokud možno plným úvazkem, jelikož přepínání úloh při tvůrčí činnosti unavuje, zdržuje, a tato režie sama zabila nejeden projekt. Výjimkou můžou být lidé, kteří neprogramují, ale jsou zapotřebí například pro údržbu serverů, podporu týmu. O těch nemluvím, ale i na ně je třeba v rozpočtu myslet.

Jakýchkoliv sledování nebo nedejbože plánování mandays se v tuhle chvíli vzdejte, jen by celý tým mátly, ale žádný užitek z nich nebude. Pamatujte, nemůžete házet na jednu hromadu Pepy a Franty, ne, ani Petra!
Můžete definovat mezitermíny dokončení "milestones" (tj. částečná implementace, která se dá považovat za hotovou část celku, a dá se například předat zákazníkovi k "osahání") včetně plánu rozpočtu, což se dá snadno a poměrně přesně průběžně kontrolovat.

Po rozjetí projektu (ne nutně po podpisu smlouvy, ale s rizikem, že k němu ani nedojde je třeba vždycky počítat), je v první řadě třeba zpřesnit analýzu tak, aby se dalo začít programovat. Není třeba udělat všechno najednou, ale je třeba mít analýzu konzistentní, abyste se netočili v kruzích.
Programování pak probíhá ideálně v iteracích, co iterace, to nějaká sada dobře naplánovaných úloh, za každou úlohu nese někdo odpovědnost, po každé iteraci se vyhodnocuje stav a případně se úloha posune do další iterace.

Toto je už věc analytiků, programátorů, manažer může přihlížet, vznášet dotazy, ale do organizace práce ostatních členů týmu by neměl nekvalifikovaně zasahovat, rozhodně ne autoritativně. Měl by ale naopak průběžně informovat programátory o stavu rozpočtu a celý tým by měl dokázat zhruba odhadnout procento implementace vůči nejbližšímu plánovanému milestone.

Definice úlohy

Definici úlohy specifikují typicky programátoři ve spolupráci s analytikem. Úloha by měla mít následující atributy:
  • Název - jednoduchý a srozumitelný alespoň všem programátorům
  • Popis - co nejpečlivější a hned na začátku rozšířený o slovní návrh implementace, plus způsob ověření funkčnosti
  • Termín - u úlohy do nejbližší iterace už závazný, u úlohy plánované na později spíše orientační
  • Pracnost - odhad programátora, spíše pesimistický než optimistický. Všichni budou šťastní, pokud se to povede napoprvé, ale málokdy se to stane. Pokud je úloha ale dokončena s nižší než odhadnutou pracností, je to pořád dobré.
  • Specifikace závislostí na jiných úlohách
Právě součet pracností úlohy je pak použitelný k dalšímu odhadu toho, zda se vše stíhá, nicméně je nutné počítat i se závislostmi a vytížeností týmu, což není tak jednoduché, jak se na první pohled zdá. Pokud to zanedbáte, riskujete, že si až pozdě všimnete, že nestíháte. Na druhou stranu, plánovat příliš podrobně příliš dopředu vás také nikam neposune, jen ztratíte čas něčím, co pak buď budete zbytečně udržovat, nebo co stejně vyhodíte.

Čas nejsou peníze

Prostý fakt je ten, že zákazníka nezajímá, kolik lidí jste ve skutečnosti v týmu měli ani kolik tým strávil "mandays" prací na díle, dokonce ani jestli jste zaměstnali dvacet čerstvých absolventů vysoké školy nebo dva specialisty za 200 tisíc měsíčně. To je věc dodavatele, aby zvolil nejlepší cestu.

Ano, zákazník se může snažit zjistit, jaký máte zisk, resp. o kolik levnější daná zakázka mohla být. Pokud vás ale chce usvědčit z toho, že jste ho obrali, stejně vám při nejbližší příležitosti uteče, a svědčí to mimo jiné o tom, že jste nějak podcenili komunikaci se zákazníkem - začal vás podezřívat.

Zákazníka hlavně zajímá to, aby dílo, které zaplatil, nemělo žádné vady a fungovalo tak, jak požadoval. Mandays používá spíše na "virtuální" ohodnocení pracnosti díla. Toto číslo ale nemá s realitou interních výkazů práce nic společného. Kdyby mělo, představte si to - zákazník má problém, tak za ním pošlete:
  • experta, který je za dvě hodiny hotový
  • sekretářku, která zavolá expertovi, který jí naviguje. Dílo též skončí po nějakých čtyřech hodinách úspěchem
Vážně si myslíte, že můžete vyfakturovat celý jeden manday (2 lidi krát 4 hodiny)?*
Krom toho plat sekretářky je jen zlomek toho, co bere expert. Seriózní firma samozřejmě vždycky pošle experta. Tento příklad se obvykle řeší smluvně trochu jinak, ale jako okatý příklad nesrovnalosti takového přístupu snad stačí.

Závěr

Jinak řečeno, ano, asi jste si už u svých velkých zakázek všimli, že se nedají moc dobře plánovat. A právě proto vznikly termíny jako agilní techniky vývoje software, extrémní programování, a další, viz oba odkazy. Pro manažera, zvyklého na vodopádový model (pokud vůbec), je to celkem nepříjemná změna, ale je to jen o zvyku - nakonec je naopak příjemné, že se pořád něco děje a pořád se to posouvá, a když po každé iteraci vidí hotové dílo, už by neměnil.

Ještě bych zmínil jeden web, http://wiki.c2.com, vypadá sice triviálně a zastarale, ale obsahuje neskutečné množství nadčasových otázek a odpovědí, týkajících se vývoje software, vysvětlených podle mého soudu celkem srozumitelnou formou včetně různých pastí. Pokud ho začnete vážně číst, je možné, že budete mít problém přestat ...

P.S.: Kniha The Mythical Man-Month byla vydána v roce 1975.

EDIT: Na základě připomínky kamaráda, vztahující se k článkům "Agile is Dead" (které si najděte sami), přidávám ještě jeden odkaz s reakcí na ně: Is the Agile Manifesto Dead?
Stručně řečeno jde o to, že se z Agile stal buzzword, obchodní značka, přičemž původně šlo spíše o apel a nějaký soupis technik, které při vývoji pomáhají. "Agilní" znamená česky "snaživý", tak se snažte dělat věci dobře, chovejte se jako tým, atd. Ne, neznamená to, že se budete doslovně držet nějakého seznamu bodů. Myslete. A mluvte spolu.

*) Pro puntičkáře - zatímco sekretářka cestovala, expert se už připravoval na její podporu a studoval logy, které dostal.