style="display:inline-block;width:728px;height:90px"
data-ad-client="ca-pub-5164839828746352"
data-ad-slot="7563230308">

Problema con Threads

Solicito la ayuda de ustedes para detectar el bug en el siguiente codigo, llevo varias horas trabajando en el y aun no doy con el problema. Les agradeceria muchisimo si se toman el tiempo de examinarlo así a ojo de buen cubero y me den algunas pistas. Expongo el problema.

Tengo una aplicacion cliente-servidor (usual en estos tiempos) donde el cliente wrapea todas las llamadas al servidor en otros threads utilizando la libreria Spin, esto es para que el thread AWT (encargado de pintar los graficos) no se congele y la aplicación no de la apariencia de que se "traba". Para hacerlo un poco mas agradable, todas las llamadas a servicios remotos las intercepto, donde si la llamada tarda mas de cierto tiempo muestro un dialogo con una barra progresiva (para que no de la impresion de que se traba y de la impresión de que está chambiando). Entonces básicamente son 3 threads: el thread AWT (quien recive la acción y la procesa, como el presionar un botón), el thread wrapeado con Spin, esto es, el thread AWT le relega la chamba al thread Spin para quedar libre de seguir dibujando graficos (pintar como deshabilitado el botón, etc) y el thread Interceptor, que se encarga se contar el tiempo desde que se inicio la llamada hasta que paso un lapso y mostrar el dialogo, así mismo este lo oculta cuando la llamada termino. El problema es que algunas veces el dialogo se queda visible y no se oculta, aunque la llamada remota haya terminado. Desde que lo implemente con linux no he tenido ese problema, pero en clientes windows me han reportado que ocacionalmente sucede. Ya le di vueltas y vueltas al código y no logro descubrir el por qué. Aqui les pongo el código y mas abajo explico mi lógica, a ver si detectan algo que se me esté pasando que sea demasiado obvio:

public class SpinMethodInterceptor implements MethodInterceptor, InitializingBean, Runnable{

        private Logger logger = LoggerFactory.getLogger(SpinMethodInterceptor.class);
        Object locker = new Object();
        Thread showThread;
        JDialog dialog;
       
        /** tiempo en milisegundos que se debe esperar para mostrar el dialogo */
        private long retraso;
       
        /** tiempo que debe esperar el thread antes de volvera verificar si ya paso el tiempo */
        private long brinco;
       
        /** Indica que se esta llamando a un servicio */
        private boolean llamando;
       
        @Override public void afterPropertiesSet() throws Exception{
               
                dialog = new WaitDialog();
                LocationUtils.centerToParent(dialog);
                brinco = 50;
                if(retraso == 0){
                        retraso = 1000;
                }
                setLlamando(false);
               
                showThread = new Thread(this);
                showThread.setName("InterceptorThread");
                showThread.setDaemon(true);
                showThread.start();
        }
       
        @Override public Object invoke(MethodInvocation invocation) throws Throwable {
                logger.debug("method intercepted: Thread Name: {}", Thread.currentThread().getName());
               
                synchronized(locker){
                        setLlamando(true);
                        locker.notify();
                }
               
                try{
                        return invocation.proceed();
                } finally{
                        setLlamando(false);
                }
        }

        private class WaitDialog extends JDialog{
                JProgressBar bar;
               
                public WaitDialog(){
                        setModalityType(Dialog.ModalityType.APPLICATION_MODAL);
                        setDefaultCloseOperation(JDialog.DO_NOTHING_ON_CLOSE);
                        setUndecorated(true);
                       
                        bar = new JProgressBar();
                       
                        JLabel label = new JLabel("Consultando Servidor...");
                       
                        JPanel pan = new JPanel();
                        pan.setLayout(new BorderLayout());
                        pan.add(label, BorderLayout.NORTH);
                        pan.add(bar, BorderLayout.CENTER);
                        pan.setBorder(BorderFactory.createEmptyBorder(3, 10, 3, 10));
                       
                        setContentPane(pan);
                        setSize(280, 50);
                }
               
                @Override public void setVisible(boolean b){
                        bar.setIndeterminate(b);
                        super.setVisible(b);
                }
        }
       
        private void setLlamando(boolean llamando){
                synchronized(locker){
                        this.llamando = llamando;
                }
        }
       
        private boolean isLlamando(){
                synchronized(locker){
                        return llamando;
                }
        }
       
        public void run() {
                long esperado = 0;
                logger.debug("Starting Interceptor Thread");
                while(true){
                        try{
                                if(isLlamando()){
                                        long diff = new Date().getTime() - esperado;
                                        if(dialog.isVisible() == false && diff >= retraso){
                                                logger.trace("Showing dialog with: {} ms", diff);
                                                SwingUtilities.invokeLater(new Runnable(){
                                                        @Override public void run() {
                                                                dialog.setVisible(true);
                                                        }
                                                });
                                        } else{
                                                //logger.trace("waiting: {}", diff);
                                                synchronized(locker){
                                                        locker.wait(brinco);
                                                }
                                        }
                                } else{
                                        if(dialog.isVisible()){
                                                logger.trace("Hidding dialog");
                                                SwingUtilities.invokeLater(new Runnable(){
                                                        @Override public void run() {
                                                                dialog.setVisible(false);
                                                        }
                                                });
                                        }
                                       
                                        //ponemos al InterceptorThread que espere por una notificacon
                                        logger.trace("Thread Waiting");
                                        synchronized(locker){
                                                locker.wait();
                                        }
                                       
                                        esperado = new Date().getTime();
                                        logger.trace("Starting call");
                                }
                        } catch(Exception ex){
                                logger.error(ex.getMessage());
                        }
                }
        }
}

Para empezar, el objeto es un singleton. Asi cuando se inicializa, configuro las variables e inicializo el thread Interceptor, el cual checa por una bandera de 'llamando', la cual esta en falsa por lo tanto se pone a dormir. Cuando sucede una llamada, el thread que entra es el Spin, este asigna la bandera de llamando a true y despierta al thread Interceptor. El thread Spin entonces procede a hacer la llamada remota, que al ser síncrona, se esperará hasta que retorne un valor. Mientras tanto el thread Interceptor esta corriendo y verificando si ya paso el lapso de tiempo para mostrar el dialogo. Si la llamada termina antes del lapso la bandera se llamando se pone a false y el thread Interceptor nunca muestra el dialogo y se pone a dormir, pero si el lapso ocurre el dialogo se muestra, sin embargo el thread interceptor sigue corriendo, esperando a que la bandera de llamando sea falsa, para en tal caso ocultar el dialogo y ponerse a dormir. No crei conveniente poner en un synchronized el cambio de visibilidad del dialogo, puesto que se hace solo desde un mismo thread.
Segun mi logica, no deberia de quedarse visible el dialogo por siempre, ya que si se mostro, va a quedar visible solo si el thread del Interceptor se pone a dormir, pero para ponerse a dormir tiene que pasar antes la verificacion de si esta visible para ocultarlo, y como solo este thread es el que hace eso, no hay problemas de accesos concurrentes al dialogo.

Entonces, ¿Que ven ustedes que yo no?

Sobres.

Opciones de visualización de comentarios

Seleccione la forma que prefiera para mostrar los comentarios y haga clic en «Guardar las opciones» para activar los cambios.
Imagen de ezamudio

mmm...

Primero que nada, algunas cosas que nada tienen que ver con la solucion, pero que podrian simplificar tantito el codigo:

- El objeto locker parece ser el unico que usas para sincronizar en este codigo. Si solamente usas ese objeto, por que no mejor usas this? y asi puedes simplificar el codigo de setLlamando y getLlamando para simplemente agregarles synchronized en la declaracion del metodo en vez de hacer el bloque interno (que solamente envuelve la unica linea de codigo del metodo).

- Tal vez me falta cafeina para terminar de bootear, pero me hace un poco de ruido que hay un bloque sincronizado dentro del cual llamas a setLlamando el cual contiene un bloque sincronizado, ambos por el mismo objeto. Pero creo que si entras a ese primer bloque, vas a entrar al segundo porque finalmente puedes sincronizar dos veces sobre el mismo objeto cuando lo haces desde el mismo hilo... tendria que probar...

- No seria mas facil usar un AtomicBoolean en vez de un boolean normal? podrias quitar los metodos setLlamando y getLlamando, declarar la variable privada llamando tipo AtomicBoolean y usar los metodos get() y set() de ese objeto, que no necesitan ser invocados dentro de un bloque sincronizado...

- Las fechas que usas son solamente para comparar los milisegundos transcurridos, asi que son algo innecesarias, mejor usa longs y captura System.currentTimeMillis()

No logro ver ahorita algo que esté evidentemente mal en tu código, pero el problema que describes sospecho que por una secuencia de eventos mas o menos asi (ya con tu Thread corriendo):

T1 es tu Thread
T2 es el thread que invoca tu codigo

T1 esta en estado Runnable, esperando sobre locker en el else del if del run() porque llegó ahi cuando arrancó, porque la bandera estaba apagada.
T2 invoca tu invokeMethod, donde activas la bandera y notificas a T1 (o a cualquier otro thread que esté esperando sobre locker, pero segun yo T1 es el único que está esperando sobre locker). Luego invocas al método y algo comienza a correr y T2 está haciendo otra cosa.
T1 despierta y toma el tiempo, pasa a otra iteración del ciclo, y se queda en el wait con timeout dentro del if de la bandera activa. Ahi va a estar pasando varias veces.

Ahora... supongamos que mientras T1 está en ese wait(brinco), T2 termina de ejecutarse y entonces apaga la bandera. T1 entonces cuando sale del brinco tiempo despues (porque no es notificado al apagarse la bandera, ya no entra a la condición en la siguiente iteración porque la bandera ya fue apagada en T2 mientras T1 esperaba. Si el diálogo no era visible, ya no aparece, pero si estaba visible, en la siguiente iteración desaparece.

Pero sospecho que hay una condición en que T2 termina, y apaga la bandera justo cuando T1 está a punto de mostrar el diálogo; T1 entra a la parte en que la bandera ya está apagada y manda cerrar el diálogo, pero como abrir y cerrar el diálogo son tareas que se encolan en el thread de Swing, es posible que primero se ejecuta la acción de cerrar e inmediatamente después se ejecuta la acción de abrir... quedando así abierto el diálogo de manera indefinida, porque T1 ya está dormido esperando a que cambie esa bandera.

A fin de cuentas, la única manera en que se puede quedar abierto el diálogo indefinidamente es porque T1 ya está esperando sobre locker y en eso se invoca setVisible(true) porque hay un cierto retraso en esa llamada (porque la encolas con SwingUtilities.invokeLater).

Tal vez se pueda arreglar poniendole un if (llamando) a la tarea que hace el setVisible(true).

Y por último... creo que sería más sencillo NO tener tu thread corriendo todo el tiempo, sino que simplemente tener un ScheduledExecutorService y en tu intercepción de método prender la bandera y aventar un Runnable que abra el diálogo, programando el Runnable para que corra en el tiempo definido que tiene que pasar para que se abra. Guardas referencia al Runnable, luego ejecutas invocation.proceed() y despues de eso, simplemente apagas la bandera y mandas cerrar el diálogo. El código de tu Runnable simplemente primero checa si la bandera está encendida, y de ser así, abre el diálogo; luego vuelve a checar si la bandera sigue encendida, y de no ser así, lo cierra (no pasa nada si lo mandas cerrar dos veces).

Imagen de Nopalin

es posible que primero se

es posible que primero se ejecuta la acción de cerrar e inmediatamente después se ejecuta la acción de abrir

En teoria no deberia ocurrir, ya que segun la documentación se encola, y las colas dicen que los elementos salen en el orden que entran y en la situación que declaras entra primero hacerlo visible y despues ocultarlo, lo que deberia mantenerlo oculto.

En fin voy a darle una revisada a lo que comentas en tu ultimo parrafo, a ver que puedo resolver.

Gracias por el tiempo tomado

sobres

Imagen de ezamudio

teoria

En teoría, la teoría y la práctica son iguales. En la práctica no...

La causa directa del problema no necesariamente es el encolamiento pero puede ser UNA de las causas. La otra es el tiempo que tarda en ejecutarse la tarea en SwingUtilities, para abrir el diálogo, y la otra es el tiempo que toma en abrir el diálogo.

Recuerda que debes tomar en cuenta ciertas condiciones en programación concurrente. Veo estas dos posibilidades:

T1 encola la tarea de abrir el diálogo. Mientras tanto, T2 termina la ejecución del método externo, apagando la bandera. T1 en su siguiente iteración ya ve la bandera apagada y entra al else, pero no encola la tarea que cierra el diálogo, porque cuando pregunta si el diálogo es visible obtiene false, porque la tarea encolada para abrir el diálogo aún no la ejecuta el SwingUtilities, porque mientras se estaba encolando, se terminó la ejecución del método externo y se apagó la bandera, de modo que cuando termina en T1 esa invocación a SwingUtilities, ya está la bandera en off, la tarea está encolada y se ejecuta el siguiente ciclo de T1 pero revisa el diálogo y no está abierto todavía, de modo que no se encola la tarea para cerrarlo, y entonces se abre y se queda abierto indefinidamente.

Soluciones rápidas y fáciles:
- Mueve de lugar el código para encolar la tarea que cierra el diálogo, a setLlamando y que se active cuando el parámetro sea false. Con eso aseguras que siempre que se invoca setLlamando(false) se mande cerrar el diálogo, evitando la condición que ya describí, que es poco probable que ocurra, pero no imposible.

- Mete un if en la tarea que abre el diálogo para que revises nuevamente la bandera y solamente abras el diálogo si realmente la bandera sigue prendida; si ya está apagada para cuando se va a invocar ese código entonces ya no abres nada.

Imagen de Nopalin

Una bandera mas

Ya me habia pasado por la mente la situación que describes y lo que hize fue agregar una bandera mas (para checar por visibilidad en lugar de la propiedad del dialogo, que como bien dices T1 aunque haya encolado el proceso no es señal de que el dialogo esté visible), para que sea el mismo T1 el encargado de abrir y cerrar el dialogo. De la forma en que expones la solución, seria T2 el encargado de cerrar el dialogo, que aunque no tiene nada que ver por que de todas formas se encola en otro thread la tarea, quisiera que solo T1 hiciera esto, asi que con la nueva bandera queda asi T1

        public void run() {
                long esperado = 0;
                boolean mostrando = false;
               
                while(true){
                        try{
                                if(isLlamando()){
                                        long diff = new Date().getTime() - esperado;
                                        if(mostrando == false && diff >= retraso){
                                                logger.trace("Showing dialog with: {} ms", diff);
                                                SwingUtilities.invokeLater(new Runnable(){
                                                        @Override public void run() {
                                                                dialog.setVisible(true);
                                                        }
                                                });
                                                mostrando = true;
                                        } else{
                                                //logger.trace("waiting: {}", diff);
                                                synchronized(locker){
                                                        locker.wait(brinco);
                                                }
                                        }
                                } else{
                                        if(mostrando){
                                                logger.trace("Hidding dialog");
                                                SwingUtilities.invokeLater(new Runnable(){
                                                        @Override public void run() {
                                                                dialog.setVisible(false);
                                                        }
                                                });
                                                mostrando = false;
                                        }
                                       
                                        //ponemos al InterceptorThread que espere por una notificacon
                                        logger.trace("Thread Waiting");
                                        synchronized(locker){
                                                locker.wait();
                                        }
                                       
                                        esperado = new Date().getTime();
                                        logger.trace("Starting call");
                                }
                        } catch(Exception ex){
                                logger.error(ex.getMessage());
                        }
                }
        }

De cualquier forma tengo que esperar hasta que los usuarios lo prueben y me retroalimenten,a ver si se solucionó.

sobres y gracias de nuez.

Imagen de ezamudio

complicaciones

Solamente complicaste tu código con esa nueva bandera y no resuelve el problema. Lo que digo es que tienes que revisar si tienes que abrir el diálogo o no, EN EL CODIGO QUE ABRE EL DIALOGO:

                                                SwingUtilities.invokeLater(new Runnable(){
                                                        @Override public void run() {
                                                                if (isLlamando()) dialog.setVisible(true);
                                                        }
                                                });

Porque ese código no sabes cuándo se va a invocar, ya que se está encolando solamente. Por qué? pues porque puede que tu bandera de llamando esté prendida cuando encolas la tarea pero que ya no esté prendida cuando se ejecute. Y ya ves que bajo circunstancias muy específicas puede no encolarse nunca la tarea que cierra el diálogo.

Una cosa muy sencilla es que en el else grande, quites el if (mostrando) (o el if (dialog.isVisible()) original) y SIEMPRE encoles la tarea de cerrar, total no pasa nada si el diálogo está cerrado o nunca se abrió y lo mandas cerrar.

Imagen de Nopalin

No tiene error

Gracias por tu ayuda, pero el error era presisamente que estaba verificando por el isVisible() del dialogo, el cual podria seguir siendo falso al momento de que termino el T2 y puso llamando a false, por lo que else del T1 nunca encolaba el apagado del dialogo. En esta forma, al ser T1 el unico que modifica la bandera de mostrando, ya no dependo del isVisible(), sino que si mostrando es verdadero, significa que se encolo la tarea de mostrar el dialogo y lo unico que hago es encolar la tarea de ocultarlo (aqui a lomejor es donde esta el punto flaco, por que estoy suponiendo que se encola, es decir, que se ejcuten en el orden en que los fui poniendo).

Sobres.

style="display:inline-block;width:728px;height:90px"
data-ad-client="ca-pub-5164839828746352"
data-ad-slot="7563230308">